[MB-12793] Intermittent lockup in ep-engine unti test test_flush_multiv_restart Created: 27/Nov/14  Updated: 27/Nov/14

Status: Open
Project: Couchbase Server
Component/s: couchbase-bucket
Affects Version/s: .master
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Dave Rigby Assignee: Chiyoung Seo
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment: Ubuntu 12.04

Issue Links:
Relates to
relates to MB-12792 Intermittent lockup in ep-engine unit... Open
Triage: Untriaged
Is this a Regression?: Unknown

 Description   
During the ep-engine commit-validation, I occasionally see a lockup in test_flush_multiv_restart.

There appears to be some kind of race between the Flusher thread (Thread 6 below) completing Flusher::completeFlush, and shutting down a vbucket.

    (gdb) thread apply all bt

    Thread 12 (Thread 0x2ad1c412d700 (LWP 23173)):
    #0 0x00002ad1bf693dbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82
    #1 0x00002ad1bf6c1dd4 in usleep (useconds=<optimized out>) at ../sysdeps/unix/sysv/linux/usleep.c:33
    #2 0x00002ad1c1a8b294 in updateStatsThread (arg=0x2ad1c0c32f00) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/memory_tracker.cc:36
    #3 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c24020) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #4 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c412d700) at pthread_create.c:308
    #5 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #6 0x0000000000000000 in ?? ()

    Thread 11 (Thread 0x2ad1c5537700 (LWP 23184)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f340, mutex=0x2ad1c0c5f308, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f300, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5fda in TaskQueue::_doSleep (this=0x2ad1c0c5f300, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f300, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f300, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=157 '\235') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=157 '\235') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c38460) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c38460) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c24940) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c5537700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 10 (Thread 0x2ad1c5336700 (LWP 23185)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f340, mutex=0x2ad1c0c5f308, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f300, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5fda in TaskQueue::_doSleep (this=0x2ad1c0c5f300, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f300, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f300, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=160 '\240') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=160 '\240') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c38540) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c38540) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c24950) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c5336700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 9 (Thread 0x2ad1c5135700 (LWP 23186)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f340, mutex=0x2ad1c0c5f308, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f300, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5fda in TaskQueue::_doSleep (this=0x2ad1c0c5f300, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f300, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f300, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=157 '\235') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=157 '\235') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c38620) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c38620) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c24960) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c5135700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 8 (Thread 0x2ad1c4f34700 (LWP 23187)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f340, mutex=0x2ad1c0c5f308, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f300, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5fda in TaskQueue::_doSleep (this=0x2ad1c0c5f300, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f300, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f300, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=176 '\260') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=176 '\260') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c38700) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c38700) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c24970) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c4f34700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 7 (Thread 0x2ad1c4d33700 (LWP 23188)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f7c0, mutex=0x2ad1c0c5f788, ms=773) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f780, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5ff3 in TaskQueue::_doSleep (this=0x2ad1c0c5f780, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:94
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f780, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f780, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=97 'a') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=97 'a') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c387e0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c387e0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c24980) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c4d33700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 6 (Thread 0x2ad1c4b32700 (LWP 23189)):
    #0 VBucketMap::isBucketCreation (this=0x2ad1c0c4c028, id=0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/vbucketmap.cc:130
    #1 0x00002ad1c1a390f6 in EventuallyPersistentStore::flushVBucket (this=0x2ad1c0c4c000, vbid=0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep.cc:2846
    #2 0x00002ad1c1a84d4a in Flusher::flushVB (this=0x2ad1c0c63780) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/flusher.cc:283
    #3 0x00002ad1c1a84828 in Flusher::completeFlush (this=0x2ad1c0c63780) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/flusher.cc:219
    #4 0x00002ad1c1a845eb in Flusher::step (this=0x2ad1c0c63780, task=0x2ad1c0c332d0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/flusher.cc:190
    #5 0x00002ad1c1ab45d9 in FlusherTask::run (this=0x2ad1c0c332d0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/tasks.cc:44
    #6 0x00002ad1c1a8e90d in ExecutorThread::run (this=0x2ad1c0c388c0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:110
    #7 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c388c0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #8 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c24990) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #9 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c4b32700) at pthread_create.c:308
    #10 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #11 0x0000000000000000 in ?? ()

    Thread 5 (Thread 0x2ad1c4931700 (LWP 23190)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f7c0, mutex=0x2ad1c0c5f788, ms=773) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f780, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5ff3 in TaskQueue::_doSleep (this=0x2ad1c0c5f780, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:94
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f780, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f780, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=144 '\220') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=144 '\220') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c389a0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c389a0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c249a0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c4931700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 4 (Thread 0x2ad1c4730700 (LWP 23191)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f7c0, mutex=0x2ad1c0c5f788, ms=773) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f780, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5ff3 in TaskQueue::_doSleep (this=0x2ad1c0c5f780, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:94
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f780, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f780, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=195 '\303') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=195 '\303') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c38a80) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c38a80) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c249b0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c4730700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 3 (Thread 0x2ad1c452f700 (LWP 23192)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f4c0, mutex=0x2ad1c0c5f488, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f480, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5fda in TaskQueue::_doSleep (this=0x2ad1c0c5f480, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f480, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f480, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=155 '\233') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=155 '\233') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c38b60) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c38b60) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c249c0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c452f700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 2 (Thread 0x2ad1c432e700 (LWP 23193)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002ad1bef6bf95 in cb_cond_timedwait (cond=0x2ad1c0c5f640, mutex=0x2ad1c0c5f608, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002ad1c1a7baa1 in SyncObject::wait (this=0x2ad1c0c5f600, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002ad1c1ab5fda in TaskQueue::_doSleep (this=0x2ad1c0c5f600, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002ad1c1ab60cb in TaskQueue::_fetchNextTask (this=0x2ad1c0c5f600, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002ad1c1ab647d in TaskQueue::fetchNextTask (this=0x2ad1c0c5f600, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002ad1c1a78947 in ExecutorPool::_nextTask (this=0x2ad1c0e05600, t=..., tick=167 '\247') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002ad1c1a789d5 in ExecutorPool::nextTask (this=0x2ad1c0e05600, t=..., tick=167 '\247') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002ad1c1a8e630 in ExecutorThread::run (this=0x2ad1c0c38c40) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002ad1c1a8e1cd in launch_executor_thread (arg=0x2ad1c0c38c40) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002ad1bef6bb4a in platform_thread_wrap (arg=0x2ad1c0c249d0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002ad1bf3bde9a in start_thread (arg=0x2ad1c432e700) at pthread_create.c:308
    #12 0x00002ad1bf6c831d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 1 (Thread 0x2ad1c05b4780 (LWP 23172)):
    #0 0x00002ad1bf693dbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82
    #1 0x00002ad1bf6c1dd4 in usleep (useconds=<optimized out>) at ../sysdeps/unix/sysv/linux/usleep.c:33
    #2 0x00002ad1c1a83cfd in Flusher::wait (this=0x2ad1c0c63780) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/flusher.cc:47
    #3 0x00002ad1c1a2f408 in EventuallyPersistentStore::stopFlusher (this=0x2ad1c0c4c000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep.cc:418
    #4 0x00002ad1c1a2eda4 in EventuallyPersistentStore::~EventuallyPersistentStore (this=0x2ad1c0c4c000, __in_chrg=<optimized out>) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep.cc:379
    #5 0x00002ad1c1a658ff in EventuallyPersistentEngine::~EventuallyPersistentEngine (this=0x2ad1c0c72000, __in_chrg=<optimized out>) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep_engine.cc:5736
    #6 0x00002ad1c1a50294 in EvpDestroy (handle=0x2ad1c0c72000, force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep_engine.cc:143
    #7 0x0000000000401c6c in mock_destroy (handle=0x609480, force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:63
    #8 0x0000000000403d8a in destroy_engine (force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:989
    #9 0x0000000000403dd1 in reload_engine (h=0x7fff45122a18, h1=0x7fff45122a10, engine=0x7fff451232ad "ep.so", cfg=0x2ad1c0c58840 "flushall_enabled=true;", init=true, force=false)
        at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:997
    #10 0x00002ad1c103091e in test_flush_multiv_restart (h=0x609480, h1=0x609480) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/tests/ep_testsuite.cc:1405
    #11 0x0000000000403fbe in execute_test (test=..., engine=0x7fff451232ad "ep.so", default_cfg=0x7fff451232c9 "flushall_enabled=true;ht_size=13;ht_locks=7")
        at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:1055
    #12 0x0000000000404704 in main (argc=9, argv=0x7fff45122d28) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:1313

You can see that Thread 6 is just looping forever trying to flush the VBucket:

(gdb) next
    218 while(!canSnooze()) {
    (gdb)
    219 flushVB();
    (gdb)
    218 while(!canSnooze()) {
    (gdb)
    219 flushVB();
    (gdb)
    218 while(!canSnooze()) {
    (gdb)
    219 flushVB();

Stepping into this, we eventually end up with flushVBucket() returning with RETRY_FLUSH_VBUCKET, as it appears that the vbucket is still marked as being created:

(gdb) step
    EventuallyPersistentStore::flushVBucket (this=0x2ad1c0c4c000, vbid=0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep.cc:2836
    2836 KVShard *shard = vbMap.getShard(vbid);
    (gdb) next
    2837 if (diskFlushAll) {
    (gdb)
    2846 if (vbMap.isBucketCreation(vbid)) {
    (gdb)
    2847 return RETRY_FLUSH_VBUCKET;
    (gdb)
    2976 }




 Comments   
Comment by Dave Rigby [ 27/Nov/14 ]
Note: Command-line for failing test (as of 1a9ae4ae0b33c83f91e74337a0e2b9d567a74875):

    build/memcached/engine_testapp -E ep.so -T ep_testsuite.so -e "flushall_enabled=true;ht_size=13;ht_locks=7" -C 138




[MB-12792] Intermittent lockup in ep-engine unit tests during unregisterBucket Created: 27/Nov/14  Updated: 27/Nov/14

Status: Open
Project: Couchbase Server
Component/s: couchbase-bucket
Affects Version/s: .master
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Dave Rigby Assignee: Chiyoung Seo
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment: Jenkins ep-engine CV build - Ubuntu 12.04 x64 - see http://factory.couchbase.com/job/ep-engine-gerrit-master/128/

Issue Links:
Relates to
relates to MB-12793 Intermittent lockup in ep-engine unti... Open
Triage: Untriaged
Operating System: Ubuntu 64-bit
Is this a Regression?: Unknown

 Description   
The Jenkins commit-validation build for ep-engine is still randomly timing out. Investigating it I found that ep-engine appears to have deadlocked during shutdown - we have somehow managed to end up with a ExecutorThread which after calling stop() has a state of EXECUTOR_SLEEPING.

GDB session of the issue - note my comments [DJR] inline:

(gdb) bt
    #0 0x00002b59d6f89148 in pthread_join (threadid=47664944314112, thread_return=0x0) at pthread_join.c:89
    #1 0x00002b59d6b35c78 in cb_join_thread (id=47664944314112) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:60
    #2 0x00002b59d968e537 in ExecutorThread::stop (this=0x2b59d8838540, wait=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:63
    #3 0x00002b59d967a68b in ExecutorPool::_unregisterBucket (this=0x2b59d8a05600, engine=0x2b59d8872000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:574
    #4 0x00002b59d967a89e in ExecutorPool::unregisterBucket (this=0x2b59d8a05600, engine=0x2b59d8872000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:602
    #5 0x00002b59d962edbc in EventuallyPersistentStore::~EventuallyPersistentStore (this=0x2b59d884c000, __in_chrg=<optimized out>) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep.cc:380
    #6 0x00002b59d96658ff in EventuallyPersistentEngine::~EventuallyPersistentEngine (this=0x2b59d8872000, __in_chrg=<optimized out>) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep_engine.cc:5736
    #7 0x00002b59d9650294 in EvpDestroy (handle=0x2b59d8872000, force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep_engine.cc:143
    #8 0x0000000000401c6c in mock_destroy (handle=0x609480, force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:63
    #9 0x0000000000403d8a in destroy_engine (force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:989
    #10 0x0000000000404015 in execute_test (test=..., engine=0x7fff265372af "ep.so", default_cfg=0x7fff265372cb "flushall_enabled=true;ht_size=13;ht_locks=7")
        at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:1061
    #11 0x0000000000404704 in main (argc=9, argv=0x7fff26535ef8) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:1313
    (gdb) f 2
    #2 0x00002b59d968e537 in ExecutorThread::stop (this=0x2b59d8838540, wait=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:63
    63 cb_join_thread(thread);
    (gdb) p this->state
    $1 = {value = EXECUTOR_SLEEPING}
    [DJR] ^^^^^^^^^^^^^^^^^
    [DJR] Note that the value is EXECUTOR_SLEEPING, even though we have just (atomically?) set it to SHUTDOWN at line 58:
    (gdb) list -
    53
    54 void ExecutorThread::stop(bool wait) {
    55 if (!wait && (state == EXECUTOR_SHUTDOWN || state == EXECUTOR_DEAD)) {
    56 return;
    57 }
    58 state = EXECUTOR_SHUTDOWN;
    59 if (!wait) {
    60 LOG(EXTENSION_LOG_INFO, "%s: Stopping", name.c_str());
    61 return;
    62 }
    (gdb) thread apply all bt

    Thread 6 (Thread 0x2b59dbd2d700 (LWP 12679)):
    #0 0x00002b59d725ddbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82
    #1 0x00002b59d728bdd4 in usleep (useconds=<optimized out>) at ../sysdeps/unix/sysv/linux/usleep.c:33
    #2 0x00002b59d968b294 in updateStatsThread (arg=0x2b59d8832f00) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/memory_tracker.cc:36
    #3 0x00002b59d6b35b4a in platform_thread_wrap (arg=0x2b59d8824020) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #4 0x00002b59d6f87e9a in start_thread (arg=0x2b59dbd2d700) at pthread_create.c:308
    #5 0x00002b59d729231d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #6 0x0000000000000000 in ?? ()

    Thread 5 (Thread 0x2b59dc12f700 (LWP 12681)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002b59d6b35f95 in cb_cond_timedwait (cond=0x2b59d885f4c0, mutex=0x2b59d885f488, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002b59d967baa1 in SyncObject::wait (this=0x2b59d885f480, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002b59d96b5fda in TaskQueue::_doSleep (this=0x2b59d885f480, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002b59d96b60cb in TaskQueue::_fetchNextTask (this=0x2b59d885f480, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002b59d96b647d in TaskQueue::fetchNextTask (this=0x2b59d885f480, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002b59d9678947 in ExecutorPool::_nextTask (this=0x2b59d8a05600, t=..., tick=121 'y') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002b59d96789d5 in ExecutorPool::nextTask (this=0x2b59d8a05600, t=..., tick=121 'y') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002b59d968e630 in ExecutorThread::run (this=0x2b59d8838540) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002b59d968e1cd in launch_executor_thread (arg=0x2b59d8838540) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002b59d6b35b4a in platform_thread_wrap (arg=0x2b59d8824a20) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002b59d6f87e9a in start_thread (arg=0x2b59dc12f700) at pthread_create.c:308
    #12 0x00002b59d729231d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 4 (Thread 0x2b59dc531700 (LWP 12683)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002b59d6b35f95 in cb_cond_timedwait (cond=0x2b59d885f4c0, mutex=0x2b59d885f488, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002b59d967baa1 in SyncObject::wait (this=0x2b59d885f480, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002b59d96b5fda in TaskQueue::_doSleep (this=0x2b59d885f480, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002b59d96b60cb in TaskQueue::_fetchNextTask (this=0x2b59d885f480, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002b59d96b647d in TaskQueue::fetchNextTask (this=0x2b59d885f480, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002b59d9678947 in ExecutorPool::_nextTask (this=0x2b59d8a05600, t=..., tick=121 'y') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002b59d96789d5 in ExecutorPool::nextTask (this=0x2b59d8a05600, t=..., tick=121 'y') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002b59d968e630 in ExecutorThread::run (this=0x2b59d8838700) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002b59d968e1cd in launch_executor_thread (arg=0x2b59d8838700) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002b59d6b35b4a in platform_thread_wrap (arg=0x2b59d8824a30) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002b59d6f87e9a in start_thread (arg=0x2b59dc531700) at pthread_create.c:308
    #12 0x00002b59d729231d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 3 (Thread 0x2b59dc933700 (LWP 12685)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002b59d6b35f95 in cb_cond_timedwait (cond=0x2b59d885f340, mutex=0x2b59d885f308, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002b59d967baa1 in SyncObject::wait (this=0x2b59d885f300, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002b59d96b5fda in TaskQueue::_doSleep (this=0x2b59d885f300, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002b59d96b60cb in TaskQueue::_fetchNextTask (this=0x2b59d885f300, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002b59d96b647d in TaskQueue::fetchNextTask (this=0x2b59d885f300, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002b59d9678947 in ExecutorPool::_nextTask (this=0x2b59d8a05600, t=..., tick=121 'y') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002b59d96789d5 in ExecutorPool::nextTask (this=0x2b59d8a05600, t=..., tick=121 'y') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002b59d968e630 in ExecutorThread::run (this=0x2b59d88388c0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002b59d968e1cd in launch_executor_thread (arg=0x2b59d88388c0) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002b59d6b35b4a in platform_thread_wrap (arg=0x2b59d8824a50) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002b59d6f87e9a in start_thread (arg=0x2b59dc933700) at pthread_create.c:308
    #12 0x00002b59d729231d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 2 (Thread 0x2b59dcf36700 (LWP 12688)):
    #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:215
    #1 0x00002b59d6b35f95 in cb_cond_timedwait (cond=0x2b59d885f640, mutex=0x2b59d885f608, ms=2000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:156
    #2 0x00002b59d967baa1 in SyncObject::wait (this=0x2b59d885f600, tv=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/syncobject.h:74
    #3 0x00002b59d96b5fda in TaskQueue::_doSleep (this=0x2b59d885f600, t=...) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:92
    #4 0x00002b59d96b60cb in TaskQueue::_fetchNextTask (this=0x2b59d885f600, t=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:117
    #5 0x00002b59d96b647d in TaskQueue::fetchNextTask (this=0x2b59d885f600, thread=..., toSleep=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/taskqueue.cc:161
    #6 0x00002b59d9678947 in ExecutorPool::_nextTask (this=0x2b59d8a05600, t=..., tick=121 'y') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:214
    #7 0x00002b59d96789d5 in ExecutorPool::nextTask (this=0x2b59d8a05600, t=..., tick=121 'y') at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:229
    #8 0x00002b59d968e630 in ExecutorThread::run (this=0x2b59d8838b60) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:78
    #9 0x00002b59d968e1cd in launch_executor_thread (arg=0x2b59d8838b60) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:34
    #10 0x00002b59d6b35b4a in platform_thread_wrap (arg=0x2b59d8824a80) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:19
    #11 0x00002b59d6f87e9a in start_thread (arg=0x2b59dcf36700) at pthread_create.c:308
    #12 0x00002b59d729231d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
    #13 0x0000000000000000 in ?? ()

    Thread 1 (Thread 0x2b59d817e780 (LWP 12678)):
    #0 0x00002b59d6f89148 in pthread_join (threadid=47664944314112, thread_return=0x0) at pthread_join.c:89
    #1 0x00002b59d6b35c78 in cb_join_thread (id=47664944314112) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/platform/src/cb_pthreads.c:60
    #2 0x00002b59d968e537 in ExecutorThread::stop (this=0x2b59d8838540, wait=true) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorthread.cc:63
    #3 0x00002b59d967a68b in ExecutorPool::_unregisterBucket (this=0x2b59d8a05600, engine=0x2b59d8872000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:574
    #4 0x00002b59d967a89e in ExecutorPool::unregisterBucket (this=0x2b59d8a05600, engine=0x2b59d8872000) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/executorpool.cc:602
    #5 0x00002b59d962edbc in EventuallyPersistentStore::~EventuallyPersistentStore (this=0x2b59d884c000, __in_chrg=<optimized out>) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep.cc:380
    #6 0x00002b59d96658ff in EventuallyPersistentEngine::~EventuallyPersistentEngine (this=0x2b59d8872000, __in_chrg=<optimized out>) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep_engine.cc:5736
    #7 0x00002b59d9650294 in EvpDestroy (handle=0x2b59d8872000, force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/ep-engine/src/ep_engine.cc:143
    #8 0x0000000000401c6c in mock_destroy (handle=0x609480, force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:63
    #9 0x0000000000403d8a in destroy_engine (force=false) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:989
    #10 0x0000000000404015 in execute_test (test=..., engine=0x7fff265372af "ep.so", default_cfg=0x7fff265372cb "flushall_enabled=true;ht_size=13;ht_locks=7")
        at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:1061
    #11 0x0000000000404704 in main (argc=9, argv=0x7fff26535ef8) at /home/jenkins/jenkins/workspace/ep-engine-gerrit-master/memcached/programs/engine_testapp/engine_testapp.c:1313

    [DJR] Note that we *do* appear to perform an atomic compare-exchange when sleeping:
    (gdb) list TaskQueue::_doSleep
    72 numToWake -= sleepers;
    73 }
    74 }
    75 }
    76
    77 bool TaskQueue::_doSleep(ExecutorThread &t) {
    78 gettimeofday(&t.now, NULL);
    79 if (less_tv(t.now, t.waketime) && manager->trySleep(queueType)) {
    80 // Atomically switch from running to sleeping; iff we were previously
    81 // running.
    (gdb)
    82 executor_state_t expected_state = EXECUTOR_RUNNING;
    83 if (!t.state.compare_exchange_strong(expected_state,
    84 EXECUTOR_SLEEPING)) {
    85 return false;
    86 }
    ... <snip>


 Comments   
Comment by Dave Rigby [ 27/Nov/14 ]
Inspecting the ep-engine code we *appear* to be correct - transitioning from RUNNING -> SLEEPING and back in the thread itself uses compare_exchange_strong(), but clearly something is going wrong.

I note that Ubuntu 12.04 (platform here) uses gcc 4.6, which while it does support <atomic>[1] doesn't fully support C++11 and hence we configure the build to *not* use std::atomic - see [2]. As a consequence we use our own CouchbaseAtomic class. Any chance there's some bug in our implementation? How do people feel about using std::atomic as long as it's present - even if that means slightly pre-C++11 compliance?

[1]: https://gcc.gnu.org/projects/cxx0x.html
[2]: http://src.couchbase.org/source/xref/trunk/ep-engine/src/config_static.h#120




[MB-12791] Parallel client for view engine Created: 27/Nov/14  Updated: 27/Nov/14

Status: Open
Project: Couchbase Server
Component/s: None
Affects Version/s: sherlock
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Minor
Reporter: Nimish Gupta Assignee: Nimish Gupta
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown




[MB-12790] Key with huge ttl gets deleted immediately after creation Created: 26/Nov/14  Updated: 27/Nov/14

Status: Open
Project: Couchbase Server
Component/s: couchbase-bucket
Affects Version/s: 3.0.1, 3.0, 3.0.2
Fix Version/s: sherlock
Security Level: Public

Type: Bug Priority: Critical
Reporter: Aruna Piravi Assignee: Chiyoung Seo
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: No

 Description   
Seeing this in 3.0 and 3.0.2.

I did 'set' on a key with different ttls. I did getMeta() on the same key in a fraction of seconds immediately after the 'set'. This is what I observed:

#ttl=300000
memc_client.set('pymc1098', exp=300000, flags=0, val="dummy val")
memc_client.getMeta('pymc1098') returns
{'deleted': 0, 'seqno': 1, 'cas': 1417045652188427002, 'flags': 0, 'expiration': 1417345651}

#ttl=3000000
memc_client.set('pymc1098', exp=3000000, flags=0, val="dummy val")
memc_client.getMeta('pymc1098') returns
{'deleted': 1, 'seqno': 2, 'cas': 1417046333163110005, 'flags': 0, 'expiration': 1417046332}
Pls note that deleted flag has been set and as a a result, Memcached returns "not found". Also seqno is 2 indicating the deletion.

[root@centos-64-x64 bin]# ./cbstats localhost:11210 key pymc1098 0
Memcached error #1: Not found

#ttl=30000000
memc_client.set('pymc1098', exp=30000000, flags=0, val="dummy val")
memc_client.getMeta('pymc1098') returns
{'deleted': 1, 'seqno': 2, 'cas': 1417046498600061006, 'flags': 0, 'expiration': 1417046497}
Same as above, key gets deleted

#ttl=300000000
memc_client.set('pymc1098', exp=300000000, flags=0, val="dummy val")
memc_client.getMeta('pymc1098') returns
{'deleted': 1, 'seqno': 2, 'cas': 1417046045117933004, 'flags': 0, 'expiration': 1417046043}

#ttl=3000000000
memc_client.set('pymc1098', exp=3000000000, flags=0, val="dummy val")
memc_client.getMeta('pymc1098') returns
{'deleted': 0, 'seqno': 1, 'cas': 1417046941842247006, 'flags': 0, 'expiration': 3000000000}

Pls see that last case is the expected behavior. And expiration is same as ttl.

Given the nature of this bug, it should be a blocker but since this always existed, I'm raising this as a critical issue.

 Comments   
Comment by Jim Walker [ 27/Nov/14 ]
Aren't those expiry times in the past?

TTL is interpreted as either a relative time from now for values under 2,592,000

Your deleted case, the TTL is being interpreted as an absolute UNIX epoch time so depends upon the CB servers system time.

3000000 > 2,592,000 so the server ensures the document is expired after Wed, 04 Feb 1970 17:20:00 GMT





[MB-12787] select * shows an error right after delete statement run Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
cbq> delete from b0 where b0.default.VMs[0].RAM = 12 limit 1;
{
    "request_id": "11092959-2992-438f-800b-fb7f757b474b",
    "signature": null,
    "results": [
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "19.081ms",
        "executionTime": "18.566ms",
        "resultCount": 0,
        "resultSize": 0
    }
}

cbq> select * from b0;
{
    "request_id": "a578af07-e35c-4ecb-af3d-cdf85ab1f6fa",
    "signature": {
        "*": "*"
    },
    "results": [
    ]
    "errors": [
        {
            "code": 5000,
            "msg": "Error doing bulk get - cause: {1 errors, starting with MCResponse status=KEY_ENOENT, opcode=GET, opaque=0, msg: Not found}"
        }
    ],
    "status": "errors",
    "metrics": {
        "elapsedTime": "15.104ms",
        "executionTime": "14.758ms",
        "resultCount": 0,
        "resultSize": 0,
        "errorCount": 1
    }
}

cbq>





[MB-12786] how json non-doc documents can be updated? Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
how json non-doc documents can be updated? set syntax is only for json docs




[MB-12785] after run dml update unset field is still present Created: 26/Nov/14  Updated: 27/Nov/14  Resolved: 27/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Colm Mchugh
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: 4h
Time Spent: Not Specified
Original Estimate: 4h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
cbq> update b0 use keys 'tjson' unset name;
{
    "request_id": "fc8e2fa2-5940-4fbd-b103-13a84332516c",
    "signature": null,
    "results": [
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "3.857ms",
        "executionTime": "3.39ms",
        "resultCount": 0,
        "resultSize": 0
    }
}

cbq> select * from b0 use keys ['tjson'];
{
    "request_id": "be38479d-01f9-4764-b06c-c9c1c575a68b",
    "signature": {
        "*": "*"
    },
    "results": [
        {
            "b0": {
                "default": {
                    "VMs": [
                        {
                            "RAM": 51,
                            "memory": 12,
                            "name": "vm_12",
                            "os": "ubuntu"
                        },
                        {
                            "RAM": 12,
                            "memory": 12,
                            "name": "vm_13",
                            "os": "windows"
                        }
                    ],
                    "_id": "query-test0014744-0",
                    "email": "3-mail@couchbase.com",
                    "job_title": "Support",
                    "join_day": 3,
                    "join_mo": 12,
                    "join_yr": 2011,
                    "mutated": 0,
                    "name": "employee-3",
                    "skills": 12345,
                    "tasks_points": {
                        "task1": {
                            "t": "ask"
                        },
                        "task2": 12.12
                    },
                    "test_rate": 12.12
                },
                "name": "new_name",
                "skills": null
            }
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "4.045ms",
        "executionTime": "3.459ms",
        "resultCount": 1,
        "resultSize": 1263
    }
}

cbq>


 Comments   
Comment by Colm Mchugh [ 27/Nov/14 ]
Commit ec555d2cbb1347f429014f718dcc49b623c6d2c4




[MB-12784] dml update: if document is not updated success status still is shown Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
doc is like:
{
  "default": {
    "VMs": [
      {
        "RAM": 51,
        "memory": 12,
        "name": "vm_12",
        "os": "ubuntu"
      },
      {
        "RAM": 12,
        "memory": 12,
        "name": "vm_13",
        "os": "windows"
      }
    ],}}

cbq> update b0 use keys 'tjson' set default.VMs.RAM=44;
{
    "request_id": "f25e346d-caf1-4a83-8aa5-0c16fab2271a",
    "signature": null,
    "results": [
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "3.545ms",
        "executionTime": "3.034ms",
        "resultCount": 0,
        "resultSize": 0
    }
}

cbq>

doc is not updated because VMs is an array, but success status is displayed




[MB-12783] need a dml doc update Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Minor
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
https://github.com/couchbaselabs/query/blob/460336460384bfe7ef5a34c9cacb625738f58c0e/docs/n1ql-dml.md

keys clause now is USE KEYS, page contains old syntax




[MB-12782] if query has both args and $<identifier> error Error evaluating projection appears Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-alpha
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Colm Mchugh
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 4h
Time Spent: Not Specified
Original Estimate: 4h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
http://172.27.33.17:8093/query?statement=select%20count%28$1%29,%20$2,%20$sel%20al%20from%20default%20&$sel=%22VMs%22&args=[%22name%22,%20%22email%22]


{
    "request_id": "1f000fc1-965d-4dbe-a376-c181b2fb709c",
    "signature": {
        "$1": "number",
        "$2": "json",
        "al": "json"
    },
    "results": [
    ]
    "errors": [
        {
            "code": 5000,
            "msg": "Error evaluating projection. - cause: No value for named parameter $sel."
        }
    ],
    "status": "errors",
    "metrics": {
        "elapsedTime": "1.684612s",
        "executionTime": "1.684494s",
        "resultCount": 0,
        "resultSize": 0,
        "errorCount": 1
    }
}





[MB-12781] an alias cannot be passed to query as an arg for rest api Created: 26/Nov/14  Updated: 26/Nov/14  Resolved: 26/Nov/14

Status: Closed
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
http://172.27.33.17:8093/query?statement=select%20count%28name%29%20$alias1%20from%20default%20d%20use%20keys%20[%22query-test0014744-0%22]&$alias1=%22cn%22

{
    "request_id": "4eac892e-4779-4c18-a2c7-f4a50a3adf8b",

    "errors": [
        {
            "code": 5000,
            "msg": "syntax error"
        }
    ],
    "status": "fatal",
    "metrics": {
        "elapsedTime": "1.641ms",
        "executionTime": "1.127ms",
        "resultCount": 0,
        "resultSize": 0,
        "errorCount": 1
    }
}


 Comments   
Comment by Gerald Sangudi [ 26/Nov/14 ]
This is a syntax error. A $param is an expression, not an alias.




[MB-12780] if arg for rest api is an array error that there is no $ARG appears Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-alpha
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Colm Mchugh
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 4h
Time Spent: Not Specified
Original Estimate: 4h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
http://172.27.33.17:8093/query?statement=select%20count%28name%29%20cn%20from%20default%20d%20use%20keys%20$keys1&$keys1=[%27query-test0014744-0%27,%20%27query-test0014744-1%27]

{
    "request_id": "5859c427-0f70-406d-bca2-fe618299ed93",
    "signature": {
        "cn": "number"
    },
    "results": [
        {
            "cn": 0
        }
    ]
    "errors": [
        {
            "code": 5000,
            "msg": "Error evaluating KEYS. - cause: No value for named parameter $keys1."
        }
    ],
    "status": "errors",
    "metrics": {
        "elapsedTime": "3.602ms",
        "executionTime": "3.44ms",
        "resultCount": 1,
        "resultSize": 31,
        "errorCount": 1
    }
}





[MB-12779] error 'starting with MCResponse status=KEY_ENOENT' when query containing key using rest api with args Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-alpha
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Colm Mchugh
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 4h
Time Spent: Not Specified
Original Estimate: 4h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
http://172.27.33.17:8093/query?statement=select%20count%28name%29%20cn%20from%20default%20d%20use%20keys%20[%27$keys1%27]&$keys1=%22query-test0014744-0%22

{
    "request_id": "39f794aa-26e8-4a56-8ea3-b1b547f0ffbd",
    "signature": {
        "cn": "number"
    },
    "results": [
        {
            "cn": 0
        }
    ]
    "errors": [
        {
            "code": 5000,
            "msg": "Error doing bulk get - cause: {1 errors, starting with MCResponse status=KEY_ENOENT, opcode=GET, opaque=0, msg: Not found}"
        }
    ],
    "status": "errors",
    "metrics": {
        "elapsedTime": "3.224ms",
        "executionTime": "2.803ms",
        "resultCount": 1,
        "resultSize": 31,
        "errorCount": 1
    }
}


query without arg runs ok:
cbq> select count(name) cn from default d use keys ['query-test0014744-0'];
{
    "request_id": "21c0e7b8-4cfa-461a-87f8-776c850f04a8",
    "signature": {
        "cn": "number"
    },
    "results": [
        {
            "cn": 1
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "2.809ms",
        "executionTime": "2.684ms",
        "resultCount": 1,
        "resultSize": 31
    }
}

cbq>





[MB-12778] [Single HDD] 24% regression in BgFetch latency and 65% regression in write queue size Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: couchbase-bucket
Affects Version/s: 3.0.2
Fix Version/s: techdebt-backlog
Security Level: Public

Type: Bug Priority: Major
Reporter: Venu Uppalapati Assignee: Venu Uppalapati
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Operating System: Windows 64-bit
Is this a Regression?: Yes

 Description   
bgfetch latency comparison:
http://cbmonitor.sc.couchbase.com/reports/html/?snapshot=zeus_251-1083_6f2_access&snapshot=zeus_302-1521_c55_access#zeus_251-1083_6f2_accesszeus_302-1521_c55_accesszeus_251-1083_6f2zeus_302-1521_c55bucket-1avg_bg_wait_time_histo

Disk write queue comparison:
http://cbmonitor.sc.couchbase.com/reports/html/?snapshot=zeus_251-1083_9b3_access&snapshot=zeus_302-1521_bd8_access#zeus_251-1083_9b3_accesszeus_302-1521_bd8_accesszeus_251-1083_9b3zeus_302-1521_bd8bucket-1disk_write_queue

This issue is not seen on RAID 10 HDD and SSD based tests.




[MB-12777] Race condition in http_request/response.go Created: 26/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-alpha
Security Level: Public

Type: Bug Priority: Major
Reporter: Manik Taneja Assignee: Colm Mchugh
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 8h
Time Spent: Not Specified
Original Estimate: 8h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
Run cbq-engine with the -race flag

1. go run -race main.go -datastore=http://localhost:9000
2. run a simple query select 1 + 1;

go race detector outputs the following :

==================
WARNING: DATA RACE
Write by goroutine 527:
  github.com/couchbaselabs/query/server.(*BaseRequest).Stop()
      /Users/manik/tuqtng/src/github.com/couchbaselabs/query/server/request.go:323 +0x131
  github.com/couchbaselabs/query/server/http.func·001()
      /Users/manik/tuqtng/src/github.com/couchbaselabs/query/server/http/http_request.go:174 +0x9b

Previous write by goroutine 533:
  github.com/couchbaselabs/query/server/http.(*httpRequest).writeResults()
      /Users/manik/tuqtng/src/github.com/couchbaselabs/query/server/http/http_response.go:127 +0x2b0
  github.com/couchbaselabs/query/server/http.(*httpRequest).Execute()
      /Users/manik/tuqtng/src/github.com/couchbaselabs/query/server/http/http_response.go:69 +0x142

Goroutine 527 (running) created at:
  github.com/couchbaselabs/query/server/http.newHttpRequest()
      /Users/manik/tuqtng/src/github.com/couchbaselabs/query/server/http/http_request.go:175 +0x12f6
  github.com/couchbaselabs/query/server/http.(*HttpEndpoint).ServeHTTP()
      /Users/manik/tuqtng/src/github.com/couchbaselabs/query/server/http/http_endpoint.go:51 +0x5c
  net/http.(*ServeMux).ServeHTTP()
      /usr/local/go/src/pkg/net/http/server.go:1511 +0x21c
  net/http.serverHandler.ServeHTTP()
      /usr/local/go/src/pkg/net/http/server.go:1673 +0x1fc
  net/http.(*conn).serve()
      /usr/local/go/src/pkg/net/http/server.go:1174 +0xf9e

Goroutine 533 (finished) created at:
  github.com/couchbaselabs/query/server.(*Server).serviceRequest()
      /Users/manik/tuqtng/src/github.com/couchbaselabs/query/server/server.go:163 +0x618
  github.com/couchbaselabs/query/server.(*Server).doServe()
      /Users/manik/tuqtng/src/github.com/couchbaselabs/query/server/server.go:108 +0xb4
==================




[MB-12776] QueryViewException: Error occured querying view default1: {u'reason': u'unsupported field in row object: \x00\x00', u'from': u'10.5.2.233:8092'} Created: 25/Nov/14  Updated: 26/Nov/14  Resolved: 26/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: view-engine
Affects Version/s: 3.0.2
Fix Version/s: 3.0.2
Security Level: Public

Type: Bug Priority: Blocker
Reporter: Sangharsh Agarwal Assignee: Harsha Havanur
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment: Build 3.0.2-1565

Triage: Untriaged
Operating System: Centos 64-bit
Link to Log File, atop/blg, CBCollectInfo, Core dump: [Source]
10.5.2.228 : https://s3.amazonaws.com/bugdb/jira/MB-12776/0ec5808c/10.5.2.228-11252014-823-diag.zip
10.5.2.228 : https://s3.amazonaws.com/bugdb/jira/MB-12776/58c51295/10.5.2.228-diag.txt.gz
10.5.2.229 : https://s3.amazonaws.com/bugdb/jira/MB-12776/889595bb/10.5.2.229-11252014-826-diag.zip
10.5.2.229 : https://s3.amazonaws.com/bugdb/jira/MB-12776/d8fd83f9/10.5.2.229-diag.txt.gz
10.5.2.230 : https://s3.amazonaws.com/bugdb/jira/MB-12776/58cc4930/10.5.2.230-diag.txt.gz
10.6.2.192 : https://s3.amazonaws.com/bugdb/jira/MB-12776/1b0d7eb3/10.6.2.192-11252014-829-diag.zip
10.6.2.192 : https://s3.amazonaws.com/bugdb/jira/MB-12776/5abd73bc/10.6.2.192-diag.txt.gz

[Destination]
10.5.2.231 : https://s3.amazonaws.com/bugdb/jira/MB-12776/b4ad9b91/10.5.2.231-11252014-831-diag.zip
10.5.2.231 : https://s3.amazonaws.com/bugdb/jira/MB-12776/ba19628b/10.5.2.231-diag.txt.gz
10.5.2.232 : https://s3.amazonaws.com/bugdb/jira/MB-12776/1c3ff817/10.5.2.232-11252014-834-diag.zip
10.5.2.232 : https://s3.amazonaws.com/bugdb/jira/MB-12776/ad275575/10.5.2.232-diag.txt.gz
10.5.2.233 : https://s3.amazonaws.com/bugdb/jira/MB-12776/65e9d871/10.5.2.233-diag.txt.gz
10.5.2.233 : https://s3.amazonaws.com/bugdb/jira/MB-12776/abd9e261/10.5.2.233-11252014-838-diag.zip
10.5.2.234 : https://s3.amazonaws.com/bugdb/jira/MB-12776/089e032d/10.5.2.234-diag.txt.gz
Is this a Regression?: Yes

 Description   
[Jenkins]
http://qa.hq.northscale.net/view/3.0%20By%20COMPONENT/job/centos_x64--107_01--rebalanceXDCR-P1/110/consoleFull

[Test Error]
'10.5.2.231:8091''10.5.2.232:8091''10.5.2.233:8091',default bucket
[2014-11-25 08:21:53,643] - [rest_client:450] INFO - index query url: http://10.5.2.228:8092/default/_design/ddoc1/_view/default0?full_set=true&stale=false
[2014-11-25 08:21:59,853] - [rest_client:450] INFO - index query url: http://10.5.2.231:8092/default/_design/ddoc1/_view/default0?full_set=true&stale=false
[2014-11-25 08:22:06,247] - [rest_client:450] INFO - index query url: http://10.5.2.228:8092/default/_design/ddoc1/_view/default1?full_set=true&stale=false
[2014-11-25 08:22:13,129] - [rest_client:450] INFO - index query url: http://10.5.2.231:8092/default/_design/ddoc1/_view/default1?full_set=true&stale=false
[2014-11-25 08:22:19,515] - [rest_client:450] INFO - index query url: http://10.5.2.228:8092/default/_design/ddoc1/_view/default2?full_set=true&stale=false
[2014-11-25 08:22:25,780] - [rest_client:450] INFO - index query url: http://10.5.2.231:8092/default/_design/ddoc1/_view/default2?full_set=true&stale=false
[2014-11-25 08:22:32,041] - [rest_client:450] INFO - index query url: http://10.5.2.228:8092/default/_design/ddoc1/_view/default3?full_set=true&stale=false
[2014-11-25 08:22:38,314] - [rest_client:450] INFO - index query url: http://10.5.2.231:8092/default/_design/ddoc1/_view/default3?full_set=true&stale=false
[2014-11-25 08:22:44,676] - [rest_client:450] INFO - index query url: http://10.5.2.228:8092/default/_design/ddoc1/_view/default4?full_set=true&stale=false
[2014-11-25 08:22:50,790] - [rest_client:450] INFO - index query url: http://10.5.2.231:8092/default/_design/ddoc1/_view/default4?full_set=true&stale=false
[2014-11-25 08:22:57,014] - [rest_client:450] INFO - index query url: http://10.5.2.228:8092/default/_design/ddoc1/_view/default0?full_set=true&stale=false
[2014-11-25 08:23:03,186] - [task:1739] INFO - Server: 10.5.2.228, Design Doc: ddoc1, View: default0, (70000 rows) expected, (70000 rows) returned
[2014-11-25 08:23:03,186] - [task:1746] INFO - expected number of rows: '70000' was found for view query
[2014-11-25 08:23:03,230] - [rest_client:450] INFO - index query url: http://10.5.2.231:8092/default/_design/ddoc1/_view/default0?full_set=true&stale=false
[2014-11-25 08:23:09,522] - [task:1739] INFO - Server: 10.5.2.231, Design Doc: ddoc1, View: default0, (70000 rows) expected, (70000 rows) returned
[2014-11-25 08:23:09,523] - [task:1746] INFO - expected number of rows: '70000' was found for view query
[2014-11-25 08:23:09,568] - [rest_client:450] INFO - index query url: http://10.5.2.228:8092/default/_design/ddoc1/_view/default1?full_set=true&stale=false
[2014-11-25 08:23:15,947] - [task:1739] INFO - Server: 10.5.2.228, Design Doc: ddoc1, View: default1, (70000 rows) expected, (70000 rows) returned
[2014-11-25 08:23:15,947] - [task:1746] INFO - expected number of rows: '70000' was found for view query
[2014-11-25 08:23:15,993] - [rest_client:450] INFO - index query url: http://10.5.2.231:8092/default/_design/ddoc1/_view/default1?full_set=true&stale=false
[2014-11-25 08:23:21,267] - [task:1739] INFO - Server: 10.5.2.231, Design Doc: ddoc1, View: default1, (70000 rows) expected, (58896 rows) returned
[('/usr/lib/python2.7/threading.py', 524, '__bootstrap', 'self.__bootstrap_inner()'), ('/usr/lib/python2.7/threading.py', 551, '__bootstrap_inner', 'self.run()'), ('lib/tasks/taskmanager.py', 31, 'run', 'task.step(self)'), ('lib/tasks/task.py', 58, 'step', 'self.check(task_manager)'), ('lib/tasks/task.py', 1764, 'check', 'self.set_exception(e)'), ('lib/tasks/future.py', 264, 'set_exception', 'print traceback.extract_stack()')]
Tue Nov 25 08:23:21 2014
[2014-11-25 08:23:21,323] - [rest_client:450] INFO - index query url: http://10.5.2.228:8092/default/_design/ddoc1/_view/default2?full_set=true&stale=false
ERROR
[('/usr/lib/python2.7/threading.py', 524, '__bootstrap', 'self.__bootstrap_inner()'), ('/usr/lib/python2.7/threading.py', 551, '__bootstrap_inner', 'self.run()'), ('testrunner.py', 262, 'run', '**self._Thread__kwargs)'), ('/usr/lib/python2.7/unittest/runner.py', 151, 'run', 'test(result)'), ('/usr/lib/python2.7/unittest/case.py', 391, '__call__', 'return self.run(*args, **kwds)'), ('/usr/lib/python2.7/unittest/case.py', 327, 'run', 'testMethod()'), ('pytests/xdcr/rebalanceXDCR.py', 281, 'swap_rebalance_replication_with_view_queries_and_ops', '[task.result(self._poll_timeout) for task in tasks]'), ('lib/tasks/future.py', 160, 'result', 'return self.__get_result()'), ('lib/tasks/future.py', 111, '__get_result', 'print traceback.extract_stack()')]
Cluster instance shutdown with force
======================================================================
ERROR: swap_rebalance_replication_with_view_queries_and_ops (xdcr.rebalanceXDCR.Rebalance)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "pytests/xdcr/rebalanceXDCR.py", line 281, in swap_rebalance_replication_with_view_queries_and_ops
    [task.result(self._poll_timeout) for task in tasks]
  File "lib/tasks/future.py", line 160, in result
    return self.__get_result()
  File "lib/tasks/future.py", line 112, in __get_result
    raise self._exception
QueryViewException: Error occured querying view default1: {u'reason': u'unsupported field in row object: \x00\x00', u'from': u'10.5.2.233:8092'}

----------------------------------------------------------------------
Ran 1 test in 1646.342s

FAILED (errors=1)
downloading 10.5.2.228

 Comments   
Comment by Sangharsh Agarwal [ 26/Nov/14 ]
I ran the test again and it passed. So it seems frequency of this error is not always occur.
Comment by Harsha Havanur [ 26/Nov/14 ]
Change has been successfully cherry-picked as 19551d2b13c953c6c5f832e848b9414558b005ca

Please verify.
Comment by Sangharsh Agarwal [ 26/Nov/14 ]
Harsha, Please resolve the bug if fix is merged. We will close it after verifying it.




[MB-12775] memcached.exe stays at 60-80% CPU, erl.exe stays at ~10% while no activity on database Created: 25/Nov/14  Updated: 27/Nov/14

Status: Open
Project: Couchbase Server
Component/s: memcached, ns_server
Affects Version/s: 3.0.1
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: neatcode Assignee: Trond Norbye
Resolution: Unresolved Votes: 0
Labels: windows
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment: Windows 8.1 64bit

Attachments: File savetodb_v1_downloads_last_5_email_messages_to_database.js     File savetodb_v2_downloads_1000_message_headers_to_database.js    
Triage: Untriaged
Operating System: Windows 64-bit
Link to Log File, atop/blg, CBCollectInfo, Core dump: I uploaded the zip file containing the logs to filedropper: http://www.filedropper.com/collectinfo-2014-11-26t021229-ns1127001-copy
Is this a Regression?: Unknown

 Description   
Server remains at extremely high CPU usage indefinitely; no activity is being performed on database -- it's just sitting.

I tried to attach a log but the following error appears in JIRA: "Cannot attach file collectinfo.zip: Unable to communicate with JIRA" (The file is under 50mb)

 Comments   
Comment by neatcode [ 25/Nov/14 ]
Looks like I can't edit the description. I wanted to add that I tried restarting the service, and the problem resurfaced. I tried restarting the computer, and the problem resurfaced as well. It's been going on for hours now.
Comment by neatcode [ 25/Nov/14 ]
Attempting to attach a screenshot in JIRA just redirected me to the page: "http://www.oracle.com/technetwork/java/index.html"
Comment by neatcode [ 25/Nov/14 ]
I uploaded the zip file containing the logs to filedropper: http://www.filedropper.com/collectinfo-2014-11-26t021229-ns1127001-copy
Comment by Dave Rigby [ 26/Nov/14 ]
Hi neatcode,

Thanks for the logs. Could you give us some more information on what events lead to this issue? What SDK(s) were you using, with what kinds of operations? SSL for data enabled/disabled?
Comment by neatcode [ 26/Nov/14 ]
savetodb_v2 is the script i was most recently working with. it saves 1000 email message headers to the database at a time. savetodb_v1 was an earlier version of the script that saved full email messages along with their message headers instead of just message headers.
Comment by neatcode [ 26/Nov/14 ]
I was using the Node SDK. I've just uploaded the most recent version of the node.js script I was using, as well as an earlier version i was using. I think the most recent version (savetodb_v2..) is the one most likely to have triggered issues, since I didn't notice the CPU spinning until recently. I'm also using N1QL as you'll see in the source. The code is a mess but it's not very long. It's just me playing around with a few libraries (pipedrive/inbox, andris9/mailparser, and couchnode).

To successfully run the code, if you should wish to do that, you will need to create or use a @yahoo.com email address, fill it with at least a few emails or up to around 2000 emails as in my case, and hardcode that email address and password into the script and run it. The script may work with a different email @domain, but I haven't used pipedrive/inbox with other email domains yet so your mileage may vary.
Comment by neatcode [ 26/Nov/14 ]
How do I determine if SSL for data is enabled or disabled? If I had to guess, I'd say it wasn't enabled since I don't remember ever doing anything that would have explicitly enabled SSL.
Comment by neatcode [ 27/Nov/14 ]
I was thinking... I'd be willing to give you guys all of the data related to couchbase on my system including the buckets. If you could give me an ftp server to upload to and tell me what files to send, I'll send them and perhaps you can replicate the problem on your end. One guess is that the data in one of my email message headers (which are stored in a "messages" bucket) wasn't processed correctly by your Node SDK or by Couchbase Server itself, given that email data can vary widely and have different charsets, etc. Of course it could be something else. Anyways, let know if you'd like me to send more, what to send, and where to send it.

Because I'm working on developing some software, I'm going to remove this couchbase installation and reinstall so I can get back to that. But I'll hold out for a bit longer to see if you get back to me with a request for files (I don't know what to backup but I'll probably backup the couchbase directory if I *do* reinstall, first).
Comment by Dave Rigby [ 27/Nov/14 ]
neatcode: If you are still seeing this behaviour (60-80% CPU on memcached.exe while idle) could you try to collect a Minidump of memcached.exe? See http://support.microsoft.com/kb/931673 for details on how to do this.

Additionally, could you restart Couchbase (after taking the minidump) and see if that results in reduced levels of CPU for memcached & erl?




[MB-12774] Build failure in memcached Created: 25/Nov/14  Updated: 26/Nov/14  Due: 25/Nov/14  Resolved: 26/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: memcached
Affects Version/s: 3.0.2
Fix Version/s: 3.0.2
Security Level: Public

Type: Bug Priority: Test Blocker
Reporter: Chris Hillery Assignee: Dave Rigby
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
Build failure on all platforms:

[ 16%] Building C object memcached/CMakeFiles/memcached_testapp.dir/tests/testapp.c.o
/home/buildbot/buildbot_slave/ubuntu-1204-x64-302-builder/build/build/memcached/tests/testapp.c: In function 'test_mb_12762_ssl_handshake_hang':
/home/buildbot/buildbot_slave/ubuntu-1204-x64-302-builder/build/build/memcached/tests/testapp.c:3473:5: error: too few arguments to function 'reconnect_to_server'
/home/buildbot/buildbot_slave/ubuntu-1204-x64-302-builder/build/build/memcached/tests/testapp.c:685:13: note: declared here
make[5]: *** [memcached/CMakeFiles/memcached_testapp.dir/tests/testapp.c.o] Error 1

Appears to have been introduced with:

commit 908acf78d16f602c0d30653218797c4e474fbb5c
Author: Dave Rigby <daver@couchbase.com>
Date: Tue Nov 25 13:01:02 2014 +0000

    MB-12762: Close SSL connection on error during handshake


 Comments   
Comment by Dave Rigby [ 26/Nov/14 ]
Fixed by: http://review.couchbase.org/#/c/43624/ (thanks Trond).




[MB-12773] Go-XDCR: No transfer of data when a second replication on same source bucket is created Created: 25/Nov/14  Updated: 25/Nov/14

Status: Open
Project: Couchbase Server
Component/s: cross-datacenter-replication
Affects Version/s: sherlock
Fix Version/s: sherlock
Security Level: Public

Type: Bug Priority: Critical
Reporter: Aruna Piravi Assignee: Xiaomei Zhang
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: PNG File Screen Shot 2014-11-25 at 2.55.55 PM.png    
Triage: Untriaged
Epic Link: XDCR next release
Is this a Regression?: No

 Description   
Consistently reproducible

Topology: Star

Steps to reproduce
--------------------------
1. Create 3 buckets default, dest, target
2. default --> dest (10000 keys replicated)
3. Now create default -> target
4. Everything seems fine in the log - pipeline creation, creation of upr streams, creation of batches, even dcp queue on default buckets shows a drain rate of 10k/sec(screenshot attached) but no data is transferred to bucket 'target'.

Log
-----
ReplicationManager14:55:15.843453 [INFO] Creating replication - sourceCluterUUID=127.0.0.1:9000, sourceBucket=default, targetClusterUUID=localhost:9000, targetBucket=target, filterName=, settings=map[source_nozzle_per_node:2 max_expected_replication_lag:1000 log_level:Info target_nozzle_per_node:2 failure_restart_interval:30 filter_expression: timeout_percentage_cap:80 checkpoint_interval:1800 optimistic_replication_threshold:256 active:true batch_size:2048 http_connection:20 replication_type:xmem batch_count:500], createReplSpec=true
ReplicationManager14:55:15.843471 [INFO] Creating replication spec - sourceCluterUUID=127.0.0.1:9000, sourceBucket=default, targetClusterUUID=localhost:9000, targetBucket=target, filterName=, settings=map[log_level:Info target_nozzle_per_node:2 failure_restart_interval:30 source_nozzle_per_node:2 max_expected_replication_lag:1000 timeout_percentage_cap:80 checkpoint_interval:1800 filter_expression: optimistic_replication_threshold:256 http_connection:20 replication_type:xmem batch_count:500 active:true batch_size:2048]
ReplicationManager14:55:15.848854 [INFO] Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_target is created and started
AdminPort14:55:15.848863 [INFO] forwardReplicationRequest
PipelineManager14:55:15.848898 [INFO] Starting the pipeline xdcr_127.0.0.1:9000_default_localhost:9000_target
XDCRFactory14:55:15.849150 [INFO] kvHosts=[127.0.0.1]
cluster=127.0.0.1:9000
ServerList=[127.0.0.1:12000]
ServerVBMap=map[127.0.0.1:12000:[0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]]
XDCRFactory14:55:15.862793 [INFO] found kv
DcpNozzle14:55:15.874883 [INFO] Constructed Dcp nozzle dcp_127.0.0.1:12000_0 with vblist [0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31]
DcpNozzle14:55:15.887750 [INFO] Constructed Dcp nozzle dcp_127.0.0.1:12000_1 with vblist [32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]
XDCRFactory14:55:15.887764 [INFO] Constructed 2 source nozzles
cluster=localhost:9000
2014/11/25 14:55:15 Warning: Finalizing a bucket with active connections.
2014/11/25 14:55:15 Warning: Finalizing a bucket with active connections.
ServerList=[127.0.0.1:12000]
ServerVBMap=map[127.0.0.1:12000:[0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]]
XDCRFactory14:55:15.917171 [INFO] Constructed 2 outgoing nozzles
XDCRRouter14:55:15.917189 [INFO] Router created with 2 downstream parts
XDCRFactory14:55:15.917193 [INFO] Constructed router
PipelineSupervisor14:55:15.917204 [INFO] Attaching pipeline supervior service
DcpNozzle14:55:15.917236 [INFO] listener &{{0xc208bb9ce0 0xc208bb9dc0 <nil> <nil> <nil> false 0xc208bb3830} 0xc208bc1c20 0xc208b3f2a0 400000000 400000000 <nil> 0x46d0fe0 0xc208bc1c80 0xc208bc1ce0 []} is registered on event 4 for Component dcp_127.0.0.1:12000_0
PipelineSupervisor14:55:15.917243 [INFO] Registering ErrorEncountered event on part dcp_127.0.0.1:12000_0
XmemNozzle14:55:15.917258 [INFO] listener &{{0xc208bb9ce0 0xc208bb9dc0 <nil> <nil> <nil> false 0xc208bb3830} 0xc208bc1c20 0xc208b3f2a0 400000000 400000000 <nil> 0x46d0fe0 0xc208bc1c80 0xc208bc1ce0 []} is registered on event 4 for Component xmem_127.0.0.1:12000_1
PipelineSupervisor14:55:15.917264 [INFO] Registering ErrorEncountered event on part xmem_127.0.0.1:12000_1
XmemNozzle14:55:15.917280 [INFO] listener &{{0xc208bb9ce0 0xc208bb9dc0 <nil> <nil> <nil> false 0xc208bb3830} 0xc208bc1c20 0xc208b3f2a0 400000000 400000000 <nil> 0x46d0fe0 0xc208bc1c80 0xc208bc1ce0 []} is registered on event 4 for Component xmem_127.0.0.1:12000_0
PipelineSupervisor14:55:15.917285 [INFO] Registering ErrorEncountered event on part xmem_127.0.0.1:12000_0
DcpNozzle14:55:15.917301 [INFO] listener &{{0xc208bb9ce0 0xc208bb9dc0 <nil> <nil> <nil> false 0xc208bb3830} 0xc208bc1c20 0xc208b3f2a0 400000000 400000000 <nil> 0x46d0fe0 0xc208bc1c80 0xc208bc1ce0 []} is registered on event 4 for Component dcp_127.0.0.1:12000_1
PipelineSupervisor14:55:15.917306 [INFO] Registering ErrorEncountered event on part dcp_127.0.0.1:12000_1
XDCRRouter14:55:15.917324 [INFO] listener &{{0xc208bb9ce0 0xc208bb9dc0 <nil> <nil> <nil> false 0xc208bb3830} 0xc208bc1c20 0xc208b3f2a0 400000000 400000000 <nil> 0x46d0fe0 0xc208bc1c80 0xc208bc1ce0 []} is registered on event 4 for Component XDCRRouter
PipelineSupervisor14:55:15.917330 [INFO] Registering ErrorEncountered event on connector XDCRRouter
XDCRFactory14:55:15.917334 [INFO] XDCR pipeline constructed
PipelineManager14:55:15.917337 [INFO] Pipeline is constructed, start it
XmemNozzle14:55:15.917376 [INFO] Xmem starting ....
XmemNozzle14:55:15.917437 [INFO] init a new batch
XmemNozzle14:55:15.919449 [INFO] ....Finish initializing....
XmemNozzle14:55:15.919467 [INFO] Xmem nozzle is started
XmemNozzle14:55:15.919474 [INFO] Xmem starting ....
XmemNozzle14:55:15.919521 [INFO] init a new batch
XmemNozzle14:55:15.922057 [INFO] ....Finish initializing....
XmemNozzle14:55:15.922082 [INFO] Xmem nozzle is started
DcpNozzle14:55:15.922284 [INFO] Dcp nozzle dcp_127.0.0.1:12000_0 starting ....
DcpNozzle14:55:15.922289 [INFO] Dcp nozzle starting ....
XmemNozzle14:55:15.922335 [INFO] xmem_127.0.0.1:12000_0 processData starts..........
XmemNozzle14:55:15.922361 [INFO] xmem_127.0.0.1:12000_1 processData starts..........
DcpNozzle14:55:15.923789 [INFO] ....Finished dcp nozzle initialization....
DcpNozzle14:55:15.923804 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=4
DcpNozzle14:55:15.923823 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=5
DcpNozzle14:55:15.923839 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=9
DcpNozzle14:55:15.923851 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=10
DcpNozzle14:55:15.923864 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=17
DcpNozzle14:55:15.923878 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=29
DcpNozzle14:55:15.923892 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=0
DcpNozzle14:55:15.923904 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=15
DcpNozzle14:55:15.923917 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=18
DcpNozzle14:55:15.923935 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=20
DcpNozzle14:55:15.923958 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=24
DcpNozzle14:55:15.923980 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=27
DcpNozzle14:55:15.923999 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=2
DcpNozzle14:55:15.924013 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=3
DcpNozzle14:55:15.924036 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=8
DcpNozzle14:55:15.924058 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=12
DcpNozzle14:55:15.924082 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=16
DcpNozzle14:55:15.924101 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=31
DcpNozzle14:55:15.924127 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=21
DcpNozzle14:55:15.924151 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=25
DcpNozzle14:55:15.924171 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=28
DcpNozzle14:55:15.924194 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=30
DcpNozzle14:55:15.924218 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=1
DcpNozzle14:55:15.924240 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=7
DcpNozzle14:55:15.924267 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=11
DcpNozzle14:55:15.924291 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=13
DcpNozzle14:55:15.924308 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=19
DcpNozzle14:55:15.924329 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=22
DcpNozzle14:55:15.924354 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=23
DcpNozzle14:55:15.924378 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=6
DcpNozzle14:55:15.924402 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=26
DcpNozzle14:55:15.924421 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=14
DcpNozzle14:55:15.924439 [INFO] Dcp nozzle is started
DcpNozzle14:55:15.924740 [INFO] Dcp nozzle dcp_127.0.0.1:12000_1 starting ....
DcpNozzle14:55:15.924749 [INFO] Dcp nozzle starting ....
14:55:15.924810 Default None UPR_STREAMREQ for vb 4 successful
14:55:15.924832 Default None UPR_STREAMREQ for vb 5 successful
14:55:15.924851 Default None UPR_STREAMREQ for vb 9 successful
14:55:15.924869 Default None UPR_STREAMREQ for vb 10 successful
14:55:15.924887 Default None UPR_STREAMREQ for vb 17 successful
14:55:15.924905 Default None UPR_STREAMREQ for vb 29 successful
14:55:15.924926 Default None UPR_STREAMREQ for vb 0 successful
14:55:15.924945 Default None UPR_STREAMREQ for vb 15 successful
14:55:15.924961 Default None UPR_STREAMREQ for vb 18 successful
14:55:15.924979 Default None UPR_STREAMREQ for vb 20 successful
14:55:15.924997 Default None UPR_STREAMREQ for vb 24 successful
DcpNozzle14:55:15.925012 [INFO] dcp_127.0.0.1:12000_0 processData starts..........
14:55:15.925058 Default None UPR_STREAMREQ for vb 27 successful
14:55:15.925077 Default None UPR_STREAMREQ for vb 2 successful
14:55:15.925157 Default None UPR_STREAMREQ for vb 3 successful
14:55:15.925300 Default None UPR_STREAMREQ for vb 8 successful
14:55:15.925377 Default None UPR_STREAMREQ for vb 12 successful
14:55:15.925430 Default None UPR_STREAMREQ for vb 16 successful
14:55:15.925503 Default None UPR_STREAMREQ for vb 31 successful
14:55:15.925573 Default None UPR_STREAMREQ for vb 21 successful
14:55:15.925645 Default None UPR_STREAMREQ for vb 25 successful
14:55:15.925746 Default None UPR_STREAMREQ for vb 28 successful
14:55:15.925805 Default None UPR_STREAMREQ for vb 30 successful
14:55:15.925908 Default None UPR_STREAMREQ for vb 1 successful
14:55:15.925944 Default None UPR_STREAMREQ for vb 7 successful
14:55:15.926028 Default None UPR_STREAMREQ for vb 11 successful
14:55:15.926082 Default None UPR_STREAMREQ for vb 13 successful
DcpNozzle14:55:15.926127 [INFO] ....Finished dcp nozzle initialization....
DcpNozzle14:55:15.926146 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=43
DcpNozzle14:55:15.926171 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=50
DcpNozzle14:55:15.926196 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=52
DcpNozzle14:55:15.926214 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=62
DcpNozzle14:55:15.926232 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=32
DcpNozzle14:55:15.926253 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=33
DcpNozzle14:55:15.926271 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=49
DcpNozzle14:55:15.926290 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=57
DcpNozzle14:55:15.926308 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=60
DcpNozzle14:55:15.926330 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=35
DcpNozzle14:55:15.926349 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=56
DcpNozzle14:55:15.926370 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=40
DcpNozzle14:55:15.926390 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=41
DcpNozzle14:55:15.926409 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=47
DcpNozzle14:55:15.926427 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=53
DcpNozzle14:55:15.926451 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=58
DcpNozzle14:55:15.926470 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=63
DcpNozzle14:55:15.926493 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=45
DcpNozzle14:55:15.926512 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=34
DcpNozzle14:55:15.926530 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=39
DcpNozzle14:55:15.926547 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=44
DcpNozzle14:55:15.926565 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=48
DcpNozzle14:55:15.926585 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=51
DcpNozzle14:55:15.926603 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=54
DcpNozzle14:55:15.926620 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=55
DcpNozzle14:55:15.926638 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=36
DcpNozzle14:55:15.926660 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=37
DcpNozzle14:55:15.926682 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=46
DcpNozzle14:55:15.926713 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=38
DcpNozzle14:55:15.926733 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=42
DcpNozzle14:55:15.926751 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=59
DcpNozzle14:55:15.926771 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=61
DcpNozzle14:55:15.926788 [INFO] Dcp nozzle is started
GenericPipeline14:55:15.926793 [INFO] All parts has been started
GenericPipeline14:55:15.926819 [INFO] -----------Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_target is started----------
14:55:15.926857 Default None UPR_STREAMREQ for vb 43 successful
14:55:15.926879 Default None UPR_STREAMREQ for vb 50 successful
14:55:15.926897 Default None UPR_STREAMREQ for vb 52 successful
14:55:15.926916 Default None UPR_STREAMREQ for vb 62 successful
14:55:15.926934 Default None UPR_STREAMREQ for vb 32 successful
14:55:15.926953 Default None UPR_STREAMREQ for vb 33 successful
14:55:15.926972 Default None UPR_STREAMREQ for vb 49 successful
14:55:15.926990 Default None UPR_STREAMREQ for vb 57 successful
DcpNozzle14:55:15.927005 [INFO] dcp_127.0.0.1:12000_1 processData starts..........
14:55:15.927049 Default None UPR_STREAMREQ for vb 19 successful
14:55:15.927069 Default None UPR_STREAMREQ for vb 22 successful
14:55:15.927091 Default None UPR_STREAMREQ for vb 23 successful
14:55:15.927109 Default None UPR_STREAMREQ for vb 6 successful
14:55:15.927126 Default None UPR_STREAMREQ for vb 26 successful
14:55:15.927144 Default None UPR_STREAMREQ for vb 14 successful
14:55:15.927667 Default None UPR_STREAMREQ for vb 60 successful
14:55:15.927690 Default None UPR_STREAMREQ for vb 35 successful
14:55:15.927708 Default None UPR_STREAMREQ for vb 56 successful
14:55:15.927725 Default None UPR_STREAMREQ for vb 40 successful
14:55:15.927741 Default None UPR_STREAMREQ for vb 41 successful
14:55:15.927757 Default None UPR_STREAMREQ for vb 47 successful
14:55:15.927772 Default None UPR_STREAMREQ for vb 53 successful
14:55:15.927787 Default None UPR_STREAMREQ for vb 58 successful
14:55:15.927803 Default None UPR_STREAMREQ for vb 63 successful
14:55:15.927821 Default None UPR_STREAMREQ for vb 45 successful
14:55:15.927840 Default None UPR_STREAMREQ for vb 34 successful
14:55:15.927863 Default None UPR_STREAMREQ for vb 39 successful
14:55:15.928160 Default None UPR_STREAMREQ for vb 44 successful
14:55:15.928179 Default None UPR_STREAMREQ for vb 48 successful
14:55:15.928197 Default None UPR_STREAMREQ for vb 51 successful
14:55:15.928216 Default None UPR_STREAMREQ for vb 54 successful
14:55:15.928234 Default None UPR_STREAMREQ for vb 55 successful
14:55:15.928444 Default None UPR_STREAMREQ for vb 36 successful
14:55:15.928464 Default None UPR_STREAMREQ for vb 37 successful
14:55:15.928483 Default None UPR_STREAMREQ for vb 46 successful
14:55:15.928695 Default None UPR_STREAMREQ for vb 38 successful
14:55:15.928716 Default None UPR_STREAMREQ for vb 42 successful
14:55:15.928734 Default None UPR_STREAMREQ for vb 59 successful
14:55:15.928751 Default None UPR_STREAMREQ for vb 61 successful
XmemNozzle14:55:15.942524 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:15.942538 [INFO] init a new batch
XmemNozzle14:55:15.942545 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:55:15.942578 [INFO] Send batch count=500
XmemNozzle14:55:15.961096 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:15.961111 [INFO] init a new batch
XmemNozzle14:55:15.961117 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:55:15.964156 [INFO] Send batch count=500
XmemNozzle14:55:15.976531 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:15.976549 [INFO] init a new batch
XmemNozzle14:55:15.976556 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 1 batches ready
XmemNozzle14:55:15.976598 [INFO] Send batch count=500
XmemNozzle14:55:15.993209 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:15.993224 [INFO] init a new batch
XmemNozzle14:55:15.993228 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:55:15.995378 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:15.995389 [INFO] init a new batch
XmemNozzle14:55:15.995393 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 1 batches ready
2014/11/25 14:55:16 Warning: Finalizing a bucket with active connections.
2014/11/25 14:55:16 Warning: Finalizing a bucket with active connections.
XmemNozzle14:55:16.007176 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:16.007190 [INFO] init a new batch
XmemNozzle14:55:16.007194 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:55:16.010383 [INFO] Send batch count=500
XmemNozzle14:55:16.021284 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:16.021296 [INFO] init a new batch
XmemNozzle14:55:16.021300 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 1 batches ready
XmemNozzle14:55:16.031113 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:16.031128 [INFO] init a new batch
XmemNozzle14:55:16.031135 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:55:16.033492 [INFO] Send batch count=500
XmemNozzle14:55:16.048207 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:16.048225 [INFO] init a new batch
XmemNozzle14:55:16.048232 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 1 batches ready
XmemNozzle14:55:16.058367 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:16.058379 [INFO] init a new batch
XmemNozzle14:55:16.058383 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 2 batches ready
XmemNozzle14:55:16.059315 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:16.059320 [INFO] init a new batch
XmemNozzle14:55:16.059323 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 2 batches ready
XmemNozzle14:55:16.075746 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:16.075763 [INFO] init a new batch
XmemNozzle14:55:16.075770 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 3 batches ready
XmemNozzle14:55:16.080462 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:16.080471 [INFO] init a new batch
XmemNozzle14:55:16.080484 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 4 batches ready
XmemNozzle14:55:16.083353 [INFO] Send batch count=500
XmemNozzle14:55:16.090886 [INFO] Send batch count=500
XmemNozzle14:55:16.097298 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:16.097306 [INFO] init a new batch
XmemNozzle14:55:16.097310 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 2 batches ready
XmemNozzle14:55:16.107902 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:16.107926 [INFO] init a new batch
XmemNozzle14:55:16.107931 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 4 batches ready
XmemNozzle14:55:16.112732 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:16.112741 [INFO] init a new batch
XmemNozzle14:55:16.112744 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 3 batches ready
XmemNozzle14:55:16.117204 [INFO] Send batch count=500
XmemNozzle14:55:16.122616 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:55:16.122624 [INFO] init a new batch
XmemNozzle14:55:16.122628 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 5 batches ready
XmemNozzle14:55:16.124225 [INFO] Send batch count=500
XmemNozzle14:55:16.131236 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:16.131243 [INFO] init a new batch
XmemNozzle14:55:16.131247 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 3 batches ready
XmemNozzle14:55:16.137993 [INFO] Send batch count=500
XmemNozzle14:55:16.144028 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:55:16.144037 [INFO] init a new batch
XmemNozzle14:55:16.144041 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 3 batches ready
XmemNozzle14:55:16.150021 [INFO] Send batch count=500
XmemNozzle14:55:16.163865 [INFO] Send batch count=500
XmemNozzle14:55:16.169007 [INFO] Send batch count=500
XmemNozzle14:55:16.176265 [INFO] Send batch count=500
XmemNozzle14:55:16.182591 [INFO] Send batch count=500
XmemNozzle14:55:16.191643 [INFO] Send batch count=500
XmemNozzle14:55:16.200172 [INFO] Send batch count=500
XmemNozzle14:55:16.207395 [INFO] Send batch count=500
XmemNozzle14:55:16.219480 [INFO] Send batch count=500
XmemNozzle14:55:16.823473 [INFO] xmem_127.0.0.1:12000_0 batch expired, moving it to ready queue
XmemNozzle14:55:16.823495 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=38) ready queue
XmemNozzle14:55:16.823500 [INFO] init a new batch
XmemNozzle14:55:16.823505 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:55:16.824591 [INFO] Send batch count=38
XmemNozzle14:55:16.923039 [INFO] xmem_127.0.0.1:12000_1 batch expired, moving it to ready queue
XmemNozzle14:55:16.923062 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=462) ready queue
XmemNozzle14:55:16.923067 [INFO] init a new batch
XmemNozzle14:55:16.923072 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 1 batches ready
XmemNozzle14:55:16.923599 [INFO] Send batch count=462




[MB-12772] EP-engine support on XDCR Built-in Time Synchronization mechnism Created: 25/Nov/14  Updated: 25/Nov/14

Status: Open
Project: Couchbase Server
Component/s: couchbase-bucket
Affects Version/s: sherlock
Fix Version/s: sherlock
Security Level: Public

Type: Task Priority: Major
Reporter: Xiaomei Zhang Assignee: Chiyoung Seo
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   
This is for tracking the requirements on ep-engine side to support XDCR built-in time synchronization mechanism.

The design spec is at https://docs.google.com/document/d/1xBjx0SDeEnWToEv1RGLHypQAkN4HWirVqQ-JtaBtlrI/edit?usp=sharing

This is a sherlock stretch goal.




[MB-12771] Go-XDCR: Pipeline broken when target bucket is recreated (replication also recreated) Created: 25/Nov/14  Updated: 25/Nov/14

Status: Open
Project: Couchbase Server
Component/s: cross-datacenter-replication
Affects Version/s: sherlock
Fix Version/s: sherlock
Security Level: Public

Type: Bug Priority: Critical
Reporter: Aruna Piravi Assignee: Xiaomei Zhang
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: PNG File Screen Shot 2014-11-25 at 2.49.55 PM.png    
Triage: Untriaged
Epic Link: XDCR next release
Is this a Regression?: No

 Description   
Consistently reproducible

Steps to reproduce
-------------------------
1. default -> dest (10000 keys transferred)
2. delete(not flush) dest bucket
3. recreate bucket with same name,
4. recreate replication

ReplicationManager14:44:59.977539 [INFO] Creating replication - sourceCluterUUID=127.0.0.1:9000, sourceBucket=default, targetClusterUUID=localhost:9000, targetBucket=dest, filterName=, settings=map[batch_size:2048 checkpoint_interval:1800 source_nozzle_per_node:2 http_connection:20 target_nozzle_per_node:2 log_level:Info failure_restart_interval:30 replication_type:xmem active:true max_expected_replication_lag:1000 filter_expression: optimistic_replication_threshold:256 batch_count:500 timeout_percentage_cap:80], createReplSpec=true
ReplicationManager14:44:59.977565 [INFO] Creating replication spec - sourceCluterUUID=127.0.0.1:9000, sourceBucket=default, targetClusterUUID=localhost:9000, targetBucket=dest, filterName=, settings=map[source_nozzle_per_node:2 batch_size:2048 checkpoint_interval:1800 log_level:Info failure_restart_interval:30 http_connection:20 target_nozzle_per_node:2 max_expected_replication_lag:1000 replication_type:xmem active:true batch_count:500 timeout_percentage_cap:80 filter_expression: optimistic_replication_threshold:256]
ReplicationManager14:44:59.982938 [INFO] Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest is created and started
AdminPort14:44:59.982948 [INFO] forwardReplicationRequest
PipelineManager14:44:59.982986 [INFO] Starting the pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest
XDCRFactory14:44:59.983228 [INFO] kvHosts=[127.0.0.1]
cluster=127.0.0.1:9000
2014/11/25 14:44:59 Warning: Finalizing a bucket with active connections.
2014/11/25 14:44:59 Warning: Finalizing a bucket with active connections.
2014/11/25 14:44:59 Warning: Finalizing a bucket with active connections.
ServerList=[127.0.0.1:12000]
ServerVBMap=map[127.0.0.1:12000:[0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]]
XDCRFactory14:45:00.000807 [INFO] found kv
DcpNozzle14:45:00.014456 [INFO] Constructed Dcp nozzle dcp_127.0.0.1:12000_0 with vblist [0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31]
DcpNozzle14:45:00.026886 [INFO] Constructed Dcp nozzle dcp_127.0.0.1:12000_1 with vblist [32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]
XDCRFactory14:45:00.026898 [INFO] Constructed 2 source nozzles
cluster=localhost:9000
2014/11/25 14:45:00 Warning: Finalizing a bucket with active connections.
2014/11/25 14:45:00 Warning: Finalizing a bucket with active connections.
ServerList=[127.0.0.1:12000]
ServerVBMap=map[127.0.0.1:12000:[0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]]
XDCRFactory14:45:00.049272 [INFO] Constructed 2 outgoing nozzles
XDCRRouter14:45:00.049285 [INFO] Router created with 2 downstream parts
XDCRFactory14:45:00.049289 [INFO] Constructed router
PipelineSupervisor14:45:00.049296 [INFO] Attaching pipeline supervior service
DcpNozzle14:45:00.049321 [INFO] listener &{{0xc2083a1f10 0xc2083a1f80 <nil> <nil> <nil> false 0xc208115660} 0xc2088cdd40 0xc20867d720 400000000 400000000 <nil> 0x46d0fe0 0xc2088cdda0 0xc2088cde00 []} is registered on event 4 for Component dcp_127.0.0.1:12000_0
PipelineSupervisor14:45:00.049325 [INFO] Registering ErrorEncountered event on part dcp_127.0.0.1:12000_0
XmemNozzle14:45:00.049335 [INFO] listener &{{0xc2083a1f10 0xc2083a1f80 <nil> <nil> <nil> false 0xc208115660} 0xc2088cdd40 0xc20867d720 400000000 400000000 <nil> 0x46d0fe0 0xc2088cdda0 0xc2088cde00 []} is registered on event 4 for Component xmem_127.0.0.1:12000_0
PipelineSupervisor14:45:00.049338 [INFO] Registering ErrorEncountered event on part xmem_127.0.0.1:12000_0
XmemNozzle14:45:00.049348 [INFO] listener &{{0xc2083a1f10 0xc2083a1f80 <nil> <nil> <nil> false 0xc208115660} 0xc2088cdd40 0xc20867d720 400000000 400000000 <nil> 0x46d0fe0 0xc2088cdda0 0xc2088cde00 []} is registered on event 4 for Component xmem_127.0.0.1:12000_1
PipelineSupervisor14:45:00.049351 [INFO] Registering ErrorEncountered event on part xmem_127.0.0.1:12000_1
DcpNozzle14:45:00.049360 [INFO] listener &{{0xc2083a1f10 0xc2083a1f80 <nil> <nil> <nil> false 0xc208115660} 0xc2088cdd40 0xc20867d720 400000000 400000000 <nil> 0x46d0fe0 0xc2088cdda0 0xc2088cde00 []} is registered on event 4 for Component dcp_127.0.0.1:12000_1
PipelineSupervisor14:45:00.049363 [INFO] Registering ErrorEncountered event on part dcp_127.0.0.1:12000_1
XDCRRouter14:45:00.049375 [INFO] listener &{{0xc2083a1f10 0xc2083a1f80 <nil> <nil> <nil> false 0xc208115660} 0xc2088cdd40 0xc20867d720 400000000 400000000 <nil> 0x46d0fe0 0xc2088cdda0 0xc2088cde00 []} is registered on event 4 for Component XDCRRouter
PipelineSupervisor14:45:00.049379 [INFO] Registering ErrorEncountered event on connector XDCRRouter
XDCRFactory14:45:00.049381 [INFO] XDCR pipeline constructed
PipelineManager14:45:00.049384 [INFO] Pipeline is constructed, start it
XmemNozzle14:45:00.049411 [INFO] Xmem starting ....
XmemNozzle14:45:00.049962 [INFO] init a new batch
XmemNozzle14:45:00.051929 [INFO] ....Finish initializing....
XmemNozzle14:45:00.051936 [INFO] Xmem nozzle is started
XmemNozzle14:45:00.051944 [INFO] Xmem starting ....
XmemNozzle14:45:00.051993 [INFO] init a new batch
XmemNozzle14:45:00.055547 [INFO] ....Finish initializing....
XmemNozzle14:45:00.055556 [INFO] Xmem nozzle is started
DcpNozzle14:45:00.055754 [INFO] Dcp nozzle dcp_127.0.0.1:12000_0 starting ....
DcpNozzle14:45:00.055760 [INFO] Dcp nozzle starting ....
XmemNozzle14:45:00.055810 [INFO] xmem_127.0.0.1:12000_0 processData starts..........
XmemNozzle14:45:00.055820 [INFO] xmem_127.0.0.1:12000_1 processData starts..........
2014/11/25 14:45:00 Warning: Finalizing a bucket with active connections.
2014/11/25 14:45:00 Warning: Finalizing a bucket with active connections.
DcpNozzle14:45:00.058104 [INFO] ....Finished dcp nozzle initialization....
DcpNozzle14:45:00.058122 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=13
DcpNozzle14:45:00.058150 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=17
DcpNozzle14:45:00.058171 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=24
DcpNozzle14:45:00.058192 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=0
DcpNozzle14:45:00.058211 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=7
DcpNozzle14:45:00.058229 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=30
DcpNozzle14:45:00.058251 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=20
DcpNozzle14:45:00.058270 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=25
DcpNozzle14:45:00.058292 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=21
DcpNozzle14:45:00.058321 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=27
DcpNozzle14:45:00.058346 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=4
DcpNozzle14:45:00.058365 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=14
DcpNozzle14:45:00.058387 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=15
DcpNozzle14:45:00.058405 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=18
DcpNozzle14:45:00.058427 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=29
DcpNozzle14:45:00.058450 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=1
DcpNozzle14:45:00.058472 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=12
DcpNozzle14:45:00.058490 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=9
DcpNozzle14:45:00.058505 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=22
DcpNozzle14:45:00.058522 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=26
DcpNozzle14:45:00.058544 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=6
DcpNozzle14:45:00.058564 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=8
DcpNozzle14:45:00.058582 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=28
DcpNozzle14:45:00.058602 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=31
DcpNozzle14:45:00.058621 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=23
DcpNozzle14:45:00.058640 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=3
DcpNozzle14:45:00.058655 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=19
DcpNozzle14:45:00.058674 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=10
DcpNozzle14:45:00.058692 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=11
DcpNozzle14:45:00.058710 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=16
DcpNozzle14:45:00.058726 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=2
DcpNozzle14:45:00.058744 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=5
DcpNozzle14:45:00.058761 [INFO] Dcp nozzle is started
DcpNozzle14:45:00.059057 [INFO] Dcp nozzle dcp_127.0.0.1:12000_1 starting ....
DcpNozzle14:45:00.059064 [INFO] Dcp nozzle starting ....
14:45:00.059117 Default None UPR_STREAMREQ for vb 13 successful
14:45:00.059136 Default None UPR_STREAMREQ for vb 17 successful
14:45:00.059153 Default None UPR_STREAMREQ for vb 24 successful
14:45:00.059169 Default None UPR_STREAMREQ for vb 0 successful
14:45:00.059186 Default None UPR_STREAMREQ for vb 7 successful
14:45:00.059203 Default None UPR_STREAMREQ for vb 30 successful
14:45:00.059219 Default None UPR_STREAMREQ for vb 20 successful
14:45:00.059236 Default None UPR_STREAMREQ for vb 25 successful
14:45:00.059251 Default None UPR_STREAMREQ for vb 21 successful
DcpNozzle14:45:00.059282 [INFO] dcp_127.0.0.1:12000_0 processData starts..........
14:45:00.059325 Default None UPR_STREAMREQ for vb 27 successful
14:45:00.059342 Default None UPR_STREAMREQ for vb 4 successful
14:45:00.059429 Default None UPR_STREAMREQ for vb 14 successful
14:45:00.059514 Default None UPR_STREAMREQ for vb 15 successful
14:45:00.059588 Default None UPR_STREAMREQ for vb 18 successful
14:45:00.059667 Default None UPR_STREAMREQ for vb 29 successful
14:45:00.059764 Default None UPR_STREAMREQ for vb 1 successful
14:45:00.059844 Default None UPR_STREAMREQ for vb 12 successful
14:45:00.059907 Default None UPR_STREAMREQ for vb 9 successful
14:45:00.059977 Default None UPR_STREAMREQ for vb 22 successful
14:45:00.060059 Default None UPR_STREAMREQ for vb 26 successful
14:45:00.060131 Default None UPR_STREAMREQ for vb 6 successful
14:45:00.060257 Default None UPR_STREAMREQ for vb 8 successful
14:45:00.060316 Default None UPR_STREAMREQ for vb 28 successful
14:45:00.060349 Default None UPR_STREAMREQ for vb 31 successful
14:45:00.060435 Default None UPR_STREAMREQ for vb 23 successful
14:45:00.060501 Default None UPR_STREAMREQ for vb 3 successful
DcpNozzle14:45:00.060528 [INFO] ....Finished dcp nozzle initialization....
DcpNozzle14:45:00.060547 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=38
DcpNozzle14:45:00.060571 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=53
DcpNozzle14:45:00.060599 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=60
DcpNozzle14:45:00.060621 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=62
DcpNozzle14:45:00.060641 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=37
DcpNozzle14:45:00.060659 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=39
DcpNozzle14:45:00.060680 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=41
DcpNozzle14:45:00.060695 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=46
DcpNozzle14:45:00.060713 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=58
DcpNozzle14:45:00.060736 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=35
DcpNozzle14:45:00.060755 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=45
DcpNozzle14:45:00.060773 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=54
DcpNozzle14:45:00.060793 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=42
DcpNozzle14:45:00.060811 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=43
DcpNozzle14:45:00.060838 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=49
DcpNozzle14:45:00.060862 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=33
DcpNozzle14:45:00.060884 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=36
DcpNozzle14:45:00.060904 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=40
DcpNozzle14:45:00.060923 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=47
DcpNozzle14:45:00.060942 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=59
DcpNozzle14:45:00.060963 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=61
DcpNozzle14:45:00.060981 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=63
DcpNozzle14:45:00.061000 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=32
DcpNozzle14:45:00.061021 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=44
DcpNozzle14:45:00.061039 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=50
DcpNozzle14:45:00.061062 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=52
DcpNozzle14:45:00.061081 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=34
DcpNozzle14:45:00.061101 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=48
DcpNozzle14:45:00.061125 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=51
DcpNozzle14:45:00.061144 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=55
DcpNozzle14:45:00.061162 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=56
DcpNozzle14:45:00.061181 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=57
DcpNozzle14:45:00.061207 [INFO] Dcp nozzle is started
GenericPipeline14:45:00.061213 [INFO] All parts has been started
GenericPipeline14:45:00.061305 [INFO] -----------Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest is started----------
14:45:00.061350 Default None UPR_STREAMREQ for vb 38 successful
14:45:00.061371 Default None UPR_STREAMREQ for vb 53 successful
14:45:00.061390 Default None UPR_STREAMREQ for vb 60 successful
14:45:00.061409 Default None UPR_STREAMREQ for vb 62 successful
14:45:00.061427 Default None UPR_STREAMREQ for vb 37 successful
14:45:00.061444 Default None UPR_STREAMREQ for vb 39 successful
14:45:00.061462 Default None UPR_STREAMREQ for vb 41 successful
14:45:00.061483 Default None UPR_STREAMREQ for vb 46 successful
14:45:00.061500 Default None UPR_STREAMREQ for vb 58 successful
14:45:00.061517 Default None UPR_STREAMREQ for vb 35 successful
14:45:00.061536 Default None UPR_STREAMREQ for vb 45 successful
DcpNozzle14:45:00.061551 [INFO] dcp_127.0.0.1:12000_1 processData starts..........
14:45:00.061597 Default None UPR_STREAMREQ for vb 54 successful
14:45:00.061631 Default None UPR_STREAMREQ for vb 19 successful
14:45:00.061654 Default None UPR_STREAMREQ for vb 10 successful
14:45:00.061671 Default None UPR_STREAMREQ for vb 11 successful
14:45:00.061691 Default None UPR_STREAMREQ for vb 16 successful
14:45:00.061710 Default None UPR_STREAMREQ for vb 2 successful
14:45:00.061730 Default None UPR_STREAMREQ for vb 5 successful
14:45:00.062630 Default None UPR_STREAMREQ for vb 42 successful
14:45:00.062662 Default None UPR_STREAMREQ for vb 43 successful
14:45:00.062681 Default None UPR_STREAMREQ for vb 49 successful
14:45:00.062700 Default None UPR_STREAMREQ for vb 33 successful
14:45:00.062720 Default None UPR_STREAMREQ for vb 36 successful
14:45:00.062738 Default None UPR_STREAMREQ for vb 40 successful
14:45:00.062762 Default None UPR_STREAMREQ for vb 47 successful
14:45:00.062784 Default None UPR_STREAMREQ for vb 59 successful
14:45:00.062802 Default None UPR_STREAMREQ for vb 61 successful
14:45:00.062820 Default None UPR_STREAMREQ for vb 63 successful
14:45:00.062841 Default None UPR_STREAMREQ for vb 32 successful
14:45:00.062871 Default None UPR_STREAMREQ for vb 44 successful
14:45:00.062896 Default None UPR_STREAMREQ for vb 50 successful
14:45:00.062922 Default None UPR_STREAMREQ for vb 52 successful
14:45:00.062941 Default None UPR_STREAMREQ for vb 34 successful
14:45:00.062960 Default None UPR_STREAMREQ for vb 48 successful
14:45:00.062991 Default None UPR_STREAMREQ for vb 51 successful
14:45:00.063016 Default None UPR_STREAMREQ for vb 55 successful
14:45:00.063040 Default None UPR_STREAMREQ for vb 56 successful
14:45:00.063064 Default None UPR_STREAMREQ for vb 57 successful
XmemNozzle14:45:00.078227 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:45:00.078242 [INFO] init a new batch
XmemNozzle14:45:00.078248 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:45:00.078263 [INFO] Send batch count=500
XmemNozzle14:45:00.086123 [ERROR] Raise error condition MCResponse status=0x08, opcode=0xa2, opaque=0, msg: Unknown error code
ReplicationManager14:45:00.086227 [INFO] Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest reported failure. The following parts are broken: map[xmem_127.0.0.1:12000_0:MCResponse status=0x08, opcode=0xa2, opaque=0, msg: Unknown error code]
ReplicationManager14:45:00.086236 [INFO] Pausing replication xdcr_127.0.0.1:9000_default_localhost:9000_dest
PipelineManager14:45:00.086241 [INFO] Try to stop the pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest
GenericPipeline14:45:00.086246 [INFO] stoppping pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest
GenericPipeline14:45:00.086253 [INFO] Trying to stop part dcp_127.0.0.1:12000_0
DcpNozzle14:45:00.086268 [INFO] Stopping DcpNozzle dcp_127.0.0.1:12000_0
2014/11/25 14:45:00 been asked to close ...
DcpNozzle14:45:00.086297 [INFO] server is stopped per request sent at 2014-11-25 14:45:00.086273143 -0800 PST
DcpNozzle14:45:00.086310 [INFO] dcp_127.0.0.1:12000_0 processData exits
DcpNozzle14:45:00.086317 [INFO] DcpNozzle dcp_127.0.0.1:12000_0 is stopped
GenericPipeline14:45:00.086321 [INFO] part dcp_127.0.0.1:12000_0 is stopped
GenericPipeline14:45:00.086327 [INFO] Trying to stop part xmem_127.0.0.1:12000_1
GenericPipeline14:45:00.086335 [INFO] Trying to stop part xmem_127.0.0.1:12000_0
GenericPipeline14:45:00.086342 [INFO] Trying to stop part dcp_127.0.0.1:12000_1
DcpNozzle14:45:00.086352 [INFO] Stopping DcpNozzle dcp_127.0.0.1:12000_1
2014/11/25 14:45:00 been asked to close ...
DcpNozzle14:45:00.086369 [INFO] server is stopped per request sent at 2014-11-25 14:45:00.086356242 -0800 PST
DcpNozzle14:45:00.086376 [INFO] dcp_127.0.0.1:12000_1 processData exits
DcpNozzle14:45:00.086381 [INFO] DcpNozzle dcp_127.0.0.1:12000_1 is stopped
GenericPipeline14:45:00.086385 [INFO] part dcp_127.0.0.1:12000_1 is stopped
GenericPipeline14:45:00.086390 [INFO] Trying to stop part xmem_127.0.0.1:12000_0
XmemNozzle14:45:00.086397 [INFO] Stop XmemNozzle xmem_127.0.0.1:12000_0
XmemNozzle14:45:00.086404 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=1) ready queue
XmemNozzle14:45:00.086408 [INFO] init a new batch
XmemNozzle14:45:00.086414 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
14:45:00.124197 Default None Exiting send command go routine ...
14:45:00.144912 Default None Exiting send command go routine ...
XmemNozzle14:45:00.894020 [INFO] xmem_127.0.0.1:12000_1 batch expired, moving it to ready queue
XmemNozzle14:45:00.894036 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=56) ready queue
XmemNozzle14:45:00.894041 [INFO] init a new batch
XmemNozzle14:45:00.894045 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 1 batches ready
XmemNozzle14:45:00.894570 [INFO] Send batch count=56
XmemNozzle14:45:00.972952 [ERROR] Raise error condition MCResponse status=0x08, opcode=0xa2, opaque=0, msg: Unknown error code
ReplicationManager14:45:00.973020 [INFO] Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest reported failure. The following parts are broken: map[xmem_127.0.0.1:12000_1:MCResponse status=0x08, opcode=0xa2, opaque=0, msg: Unknown error code]

Screenshot of dcp queues (see last spike) attached.




[MB-12770] Go-XDCR: Replication stuck with "sendSingle: transmit error: write tcp IP:12000: broken pipe" (64 vbuckets) Created: 25/Nov/14  Updated: 25/Nov/14

Status: Open
Project: Couchbase Server
Component/s: cross-datacenter-replication
Affects Version/s: sherlock
Fix Version/s: sherlock
Security Level: Public

Type: Bug Priority: Critical
Reporter: Aruna Piravi Assignee: Xiaomei Zhang
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: PNG File Screen Shot 2014-11-25 at 2.35.01 PM.png    
Triage: Untriaged
Epic Link: XDCR next release
Is this a Regression?: No

 Description   
Inconsistent in nature. Could be related to MB-12632 per Xiaomei.

Seen this many times before. In this run, I did a make dataclean so it was a fresh cluster. I had 3 buckets created in my cluster. Tried to create replication between default and dest buckets.

AdminPort14:30:08.325226 [INFO] doCreateReplicationRequest called
ReplicationManager14:30:08.325283 [INFO] Creating replication - sourceCluterUUID=127.0.0.1:9000, sourceBucket=default, targetClusterUUID=localhost:9000, targetBucket=dest, filterName=, settings=map[batch_count:500 active:true checkpoint_interval:1800 optimistic_replication_threshold:256 http_connection:20 source_nozzle_per_node:2 target_nozzle_per_node:2 replication_type:xmem batch_size:2048 max_expected_replication_lag:1000 timeout_percentage_cap:80 failure_restart_interval:30 log_level:Info filter_expression:], createReplSpec=true
ReplicationManager14:30:08.325301 [INFO] Creating replication spec - sourceCluterUUID=127.0.0.1:9000, sourceBucket=default, targetClusterUUID=localhost:9000, targetBucket=dest, filterName=, settings=map[active:true checkpoint_interval:1800 batch_count:500 http_connection:20 source_nozzle_per_node:2 target_nozzle_per_node:2 replication_type:xmem batch_size:2048 optimistic_replication_threshold:256 max_expected_replication_lag:1000 timeout_percentage_cap:80 log_level:Info filter_expression: failure_restart_interval:30]
ReplicationManager14:30:08.330582 [INFO] Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest is created and started
AdminPort14:30:08.330593 [INFO] forwardReplicationRequest
PipelineManager14:30:08.330626 [INFO] Starting the pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest
XDCRFactory14:30:08.330876 [INFO] kvHosts=[127.0.0.1]
cluster=127.0.0.1:9000
2014/11/25 14:30:08 Warning: Finalizing a bucket with active connections.
ServerList=[127.0.0.1:12000]
ServerVBMap=map[127.0.0.1:12000:[0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]]
XDCRFactory14:30:08.344569 [INFO] found kv
DcpNozzle14:30:08.354537 [INFO] Constructed Dcp nozzle dcp_127.0.0.1:12000_0 with vblist [0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31]
DcpNozzle14:30:08.365397 [INFO] Constructed Dcp nozzle dcp_127.0.0.1:12000_1 with vblist [32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]
XDCRFactory14:30:08.365410 [INFO] Constructed 2 source nozzles
cluster=localhost:9000
2014/11/25 14:30:08 Warning: Finalizing a bucket with active connections.
2014/11/25 14:30:08 Warning: Finalizing a bucket with active connections.
ServerList=[127.0.0.1:12000]
ServerVBMap=map[127.0.0.1:12000:[0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63]]
XDCRFactory14:30:08.388646 [INFO] Constructed 2 outgoing nozzles
XDCRRouter14:30:08.388660 [INFO] Router created with 2 downstream parts
XDCRFactory14:30:08.388663 [INFO] Constructed router
PipelineSupervisor14:30:08.388671 [INFO] Attaching pipeline supervior service
DcpNozzle14:30:08.388695 [INFO] listener &{{0xc2084bb420 0xc2084bb490 <nil> <nil> <nil> false 0xc2087bbfa0} 0xc208a035c0 0xc208b8ba80 400000000 400000000 <nil> 0x46d0fe0 0xc208a03620 0xc208a03680 []} is registered on event 4 for Component dcp_127.0.0.1:12000_0
PipelineSupervisor14:30:08.388699 [INFO] Registering ErrorEncountered event on part dcp_127.0.0.1:12000_0
XmemNozzle14:30:08.388709 [INFO] listener &{{0xc2084bb420 0xc2084bb490 <nil> <nil> <nil> false 0xc2087bbfa0} 0xc208a035c0 0xc208b8ba80 400000000 400000000 <nil> 0x46d0fe0 0xc208a03620 0xc208a03680 []} is registered on event 4 for Component xmem_127.0.0.1:12000_1
PipelineSupervisor14:30:08.388713 [INFO] Registering ErrorEncountered event on part xmem_127.0.0.1:12000_1
XmemNozzle14:30:08.388722 [INFO] listener &{{0xc2084bb420 0xc2084bb490 <nil> <nil> <nil> false 0xc2087bbfa0} 0xc208a035c0 0xc208b8ba80 400000000 400000000 <nil> 0x46d0fe0 0xc208a03620 0xc208a03680 []} is registered on event 4 for Component xmem_127.0.0.1:12000_0
PipelineSupervisor14:30:08.388726 [INFO] Registering ErrorEncountered event on part xmem_127.0.0.1:12000_0
DcpNozzle14:30:08.388734 [INFO] listener &{{0xc2084bb420 0xc2084bb490 <nil> <nil> <nil> false 0xc2087bbfa0} 0xc208a035c0 0xc208b8ba80 400000000 400000000 <nil> 0x46d0fe0 0xc208a03620 0xc208a03680 []} is registered on event 4 for Component dcp_127.0.0.1:12000_1
PipelineSupervisor14:30:08.388738 [INFO] Registering ErrorEncountered event on part dcp_127.0.0.1:12000_1
XDCRRouter14:30:08.388750 [INFO] listener &{{0xc2084bb420 0xc2084bb490 <nil> <nil> <nil> false 0xc2087bbfa0} 0xc208a035c0 0xc208b8ba80 400000000 400000000 <nil> 0x46d0fe0 0xc208a03620 0xc208a03680 []} is registered on event 4 for Component XDCRRouter
PipelineSupervisor14:30:08.388754 [INFO] Registering ErrorEncountered event on connector XDCRRouter
XDCRFactory14:30:08.388756 [INFO] XDCR pipeline constructed
PipelineManager14:30:08.388759 [INFO] Pipeline is constructed, start it
XmemNozzle14:30:08.388785 [INFO] Xmem starting ....
XmemNozzle14:30:08.388855 [INFO] init a new batch
XmemNozzle14:30:08.391947 [INFO] ....Finish initializing....
XmemNozzle14:30:08.391960 [INFO] Xmem nozzle is started
XmemNozzle14:30:08.391972 [INFO] Xmem starting ....
XmemNozzle14:30:08.392025 [INFO] init a new batch
XmemNozzle14:30:08.393793 [INFO] ....Finish initializing....
XmemNozzle14:30:08.393801 [INFO] Xmem nozzle is started
DcpNozzle14:30:08.394001 [INFO] Dcp nozzle dcp_127.0.0.1:12000_0 starting ....
DcpNozzle14:30:08.394008 [INFO] Dcp nozzle starting ....
XmemNozzle14:30:08.394049 [ERROR] xmem_127.0.0.1:12000_1 Quit receiveResponse. err=EOF
XmemNozzle14:30:08.394052 [INFO] xmem_127.0.0.1:12000_1 receiveResponse exits
XmemNozzle14:30:08.394057 [INFO] xmem_127.0.0.1:12000_1 processData starts..........
XmemNozzle14:30:08.394065 [ERROR] xmem_127.0.0.1:12000_0 Quit receiveResponse. err=EOF
XmemNozzle14:30:08.394068 [INFO] xmem_127.0.0.1:12000_0 receiveResponse exits
XmemNozzle14:30:08.394071 [INFO] xmem_127.0.0.1:12000_0 processData starts..........
2014/11/25 14:30:08 Warning: Finalizing a bucket with active connections.
2014/11/25 14:30:08 Warning: Finalizing a bucket with active connections.
DcpNozzle14:30:08.396507 [INFO] ....Finished dcp nozzle initialization....
DcpNozzle14:30:08.396530 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=10
DcpNozzle14:30:08.396550 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=12
DcpNozzle14:30:08.396566 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=20
DcpNozzle14:30:08.396579 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=30
DcpNozzle14:30:08.396591 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=0
DcpNozzle14:30:08.396603 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=3
DcpNozzle14:30:08.396615 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=7
DcpNozzle14:30:08.396630 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=19
DcpNozzle14:30:08.396645 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=27
DcpNozzle14:30:08.396661 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=4
DcpNozzle14:30:08.396687 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=11
DcpNozzle14:30:08.396712 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=17
DcpNozzle14:30:08.396733 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=16
DcpNozzle14:30:08.396751 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=21
DcpNozzle14:30:08.396773 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=22
DcpNozzle14:30:08.396794 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=1
DcpNozzle14:30:08.396822 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=5
DcpNozzle14:30:08.396841 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=8
DcpNozzle14:30:08.396861 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=18
DcpNozzle14:30:08.396886 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=23
DcpNozzle14:30:08.396915 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=28
DcpNozzle14:30:08.396934 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=13
DcpNozzle14:30:08.396951 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=29
DcpNozzle14:30:08.396965 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=31
DcpNozzle14:30:08.396977 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=15
DcpNozzle14:30:08.396989 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=26
DcpNozzle14:30:08.397003 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=9
DcpNozzle14:30:08.397020 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=24
DcpNozzle14:30:08.397042 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=25
DcpNozzle14:30:08.397062 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=2
DcpNozzle14:30:08.397087 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=6
DcpNozzle14:30:08.397117 [INFO] dcp_127.0.0.1:12000_0 starting vb stream for vb=14
DcpNozzle14:30:08.397136 [INFO] Dcp nozzle is started
DcpNozzle14:30:08.397406 [INFO] Dcp nozzle dcp_127.0.0.1:12000_1 starting ....
DcpNozzle14:30:08.397417 [INFO] Dcp nozzle starting ....
14:30:08.397475 Default None UPR_STREAMREQ for vb 10 successful
14:30:08.397501 Default None UPR_STREAMREQ for vb 12 successful
14:30:08.397523 Default None UPR_STREAMREQ for vb 20 successful
14:30:08.397540 Default None UPR_STREAMREQ for vb 30 successful
14:30:08.397556 Default None UPR_STREAMREQ for vb 0 successful
14:30:08.397576 Default None UPR_STREAMREQ for vb 3 successful
14:30:08.397599 Default None UPR_STREAMREQ for vb 7 successful
14:30:08.397616 Default None UPR_STREAMREQ for vb 19 successful
14:30:08.397637 Default None UPR_STREAMREQ for vb 27 successful
14:30:08.397659 Default None UPR_STREAMREQ for vb 4 successful
14:30:08.397676 Default None UPR_STREAMREQ for vb 11 successful
DcpNozzle14:30:08.397692 [INFO] dcp_127.0.0.1:12000_0 processData starts..........
14:30:08.397760 Default None UPR_STREAMREQ for vb 17 successful
14:30:08.397784 Default None UPR_STREAMREQ for vb 16 successful
14:30:08.397882 Default None UPR_STREAMREQ for vb 21 successful
14:30:08.397945 Default None UPR_STREAMREQ for vb 22 successful
14:30:08.398020 Default None UPR_STREAMREQ for vb 1 successful
14:30:08.398095 Default None UPR_STREAMREQ for vb 5 successful
14:30:08.398191 Default None UPR_STREAMREQ for vb 8 successful
14:30:08.398282 Default None UPR_STREAMREQ for vb 18 successful
14:30:08.398359 Default None UPR_STREAMREQ for vb 23 successful
14:30:08.398423 Default None UPR_STREAMREQ for vb 28 successful
14:30:08.398497 Default None UPR_STREAMREQ for vb 13 successful
14:30:08.398632 Default None UPR_STREAMREQ for vb 29 successful
14:30:08.398719 Default None UPR_STREAMREQ for vb 31 successful
14:30:08.398734 Default None UPR_STREAMREQ for vb 15 successful
14:30:08.398811 Default None UPR_STREAMREQ for vb 26 successful
14:30:08.398881 Default None UPR_STREAMREQ for vb 9 successful
DcpNozzle14:30:08.398919 [INFO] ....Finished dcp nozzle initialization....
DcpNozzle14:30:08.398929 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=32
DcpNozzle14:30:08.398959 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=33
DcpNozzle14:30:08.398981 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=37
DcpNozzle14:30:08.399004 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=52
DcpNozzle14:30:08.399025 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=58
DcpNozzle14:30:08.399049 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=59
DcpNozzle14:30:08.399070 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=63
DcpNozzle14:30:08.399093 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=40
DcpNozzle14:30:08.399120 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=46
DcpNozzle14:30:08.399142 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=50
DcpNozzle14:30:08.399162 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=51
DcpNozzle14:30:08.399177 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=55
DcpNozzle14:30:08.399200 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=56
DcpNozzle14:30:08.399222 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=34
DcpNozzle14:30:08.399244 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=36
DcpNozzle14:30:08.399273 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=45
DcpNozzle14:30:08.399298 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=53
DcpNozzle14:30:08.399319 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=38
DcpNozzle14:30:08.399338 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=54
DcpNozzle14:30:08.399359 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=57
DcpNozzle14:30:08.399378 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=62
DcpNozzle14:30:08.399397 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=35
DcpNozzle14:30:08.399416 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=39
DcpNozzle14:30:08.399436 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=44
DcpNozzle14:30:08.399455 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=48
DcpNozzle14:30:08.399474 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=49
DcpNozzle14:30:08.399497 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=60
DcpNozzle14:30:08.399518 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=61
DcpNozzle14:30:08.399543 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=42
DcpNozzle14:30:08.399563 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=43
DcpNozzle14:30:08.399584 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=41
DcpNozzle14:30:08.399606 [INFO] dcp_127.0.0.1:12000_1 starting vb stream for vb=47
DcpNozzle14:30:08.399626 [INFO] Dcp nozzle is started
GenericPipeline14:30:08.399632 [INFO] All parts has been started
GenericPipeline14:30:08.399658 [INFO] -----------Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_dest is started----------
14:30:08.399702 Default None UPR_STREAMREQ for vb 32 successful
14:30:08.399728 Default None UPR_STREAMREQ for vb 33 successful
14:30:08.399750 Default None UPR_STREAMREQ for vb 37 successful
14:30:08.399769 Default None UPR_STREAMREQ for vb 52 successful
14:30:08.399789 Default None UPR_STREAMREQ for vb 58 successful
14:30:08.399807 Default None UPR_STREAMREQ for vb 59 successful
14:30:08.399823 Default None UPR_STREAMREQ for vb 63 successful
14:30:08.399844 Default None UPR_STREAMREQ for vb 40 successful
14:30:08.399861 Default None UPR_STREAMREQ for vb 46 successful
14:30:08.399878 Default None UPR_STREAMREQ for vb 50 successful
14:30:08.399896 Default None UPR_STREAMREQ for vb 51 successful
DcpNozzle14:30:08.399910 [INFO] dcp_127.0.0.1:12000_1 processData starts..........
14:30:08.399961 Default None UPR_STREAMREQ for vb 24 successful
14:30:08.399981 Default None UPR_STREAMREQ for vb 25 successful
14:30:08.400002 Default None UPR_STREAMREQ for vb 2 successful
14:30:08.400019 Default None UPR_STREAMREQ for vb 6 successful
14:30:08.400037 Default None UPR_STREAMREQ for vb 14 successful
14:30:08.400655 Default None UPR_STREAMREQ for vb 55 successful
14:30:08.400679 Default None UPR_STREAMREQ for vb 56 successful
14:30:08.400698 Default None UPR_STREAMREQ for vb 34 successful
14:30:08.400716 Default None UPR_STREAMREQ for vb 36 successful
14:30:08.400734 Default None UPR_STREAMREQ for vb 45 successful
14:30:08.400751 Default None UPR_STREAMREQ for vb 53 successful
14:30:08.400768 Default None UPR_STREAMREQ for vb 38 successful
14:30:08.400787 Default None UPR_STREAMREQ for vb 54 successful
14:30:08.400805 Default None UPR_STREAMREQ for vb 57 successful
14:30:08.400823 Default None UPR_STREAMREQ for vb 62 successful
14:30:08.400845 Default None UPR_STREAMREQ for vb 35 successful
14:30:08.400866 Default None UPR_STREAMREQ for vb 39 successful
14:30:08.401123 Default None UPR_STREAMREQ for vb 44 successful
14:30:08.401146 Default None UPR_STREAMREQ for vb 48 successful
14:30:08.401166 Default None UPR_STREAMREQ for vb 49 successful
14:30:08.401184 Default None UPR_STREAMREQ for vb 60 successful
14:30:08.401330 Default None UPR_STREAMREQ for vb 61 successful
14:30:08.401353 Default None UPR_STREAMREQ for vb 42 successful
14:30:08.401454 Default None UPR_STREAMREQ for vb 43 successful
14:30:08.401476 Default None UPR_STREAMREQ for vb 41 successful
14:30:08.401588 Default None UPR_STREAMREQ for vb 47 successful
XmemNozzle14:30:08.413573 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.413591 [INFO] init a new batch
XmemNozzle14:30:08.413597 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:30:08.413624 [INFO] Send batch count=500
XmemNozzle14:30:08.413734 [ERROR] xmem_127.0.0.1:12000_0 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.413746 [INFO] xmem_127.0.0.1:12000_0 connection is broken, try to repair...
XmemNozzle14:30:08.413765 [INFO] xmem_127.0.0.1:12000_0 - The connection is repaired
XmemNozzle14:30:08.414584 [INFO] xmem_127.0.0.1:12000_0 - The unresponded items are resent
XmemNozzle14:30:08.414614 [ERROR] xmem_127.0.0.1:12000_0 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.414622 [INFO] xmem_127.0.0.1:12000_0 connection is broken, try to repair...
XmemNozzle14:30:08.414638 [INFO] xmem_127.0.0.1:12000_0 - The connection is repaired
XmemNozzle14:30:08.415461 [INFO] xmem_127.0.0.1:12000_0 - The unresponded items are resent
XmemNozzle14:30:08.415490 [ERROR] xmem_127.0.0.1:12000_0 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.415498 [INFO] xmem_127.0.0.1:12000_0 connection is broken, try to repair...
XmemNozzle14:30:08.415513 [INFO] xmem_127.0.0.1:12000_0 - The connection is repaired
XmemNozzle14:30:08.416339 [INFO] xmem_127.0.0.1:12000_0 - The unresponded items are resent
XmemNozzle14:30:08.416378 [ERROR] xmem_127.0.0.1:12000_0 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.416387 [INFO] xmem_127.0.0.1:12000_0 connection is broken, try to repair...
XmemNozzle14:30:08.416404 [INFO] xmem_127.0.0.1:12000_0 - The connection is repaired
XmemNozzle14:30:08.417222 [INFO] xmem_127.0.0.1:12000_0 - The unresponded items are resent
XmemNozzle14:30:08.417257 [ERROR] xmem_127.0.0.1:12000_0 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.417265 [INFO] xmem_127.0.0.1:12000_0 connection is broken, try to repair...
XmemNozzle14:30:08.417282 [INFO] xmem_127.0.0.1:12000_0 - The connection is repaired
XmemNozzle14:30:08.418129 [INFO] xmem_127.0.0.1:12000_0 - The unresponded items are resent
XmemNozzle14:30:08.418161 [ERROR] xmem_127.0.0.1:12000_0 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.418169 [INFO] xmem_127.0.0.1:12000_0 connection is broken, try to repair...
XmemNozzle14:30:08.418184 [INFO] xmem_127.0.0.1:12000_0 - The connection is repaired
XmemNozzle14:30:08.419002 [INFO] xmem_127.0.0.1:12000_0 - The unresponded items are resent
XmemNozzle14:30:08.419034 [ERROR] xmem_127.0.0.1:12000_0 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.419042 [INFO] xmem_127.0.0.1:12000_0 connection is broken, try to repair...
XmemNozzle14:30:08.419056 [INFO] xmem_127.0.0.1:12000_0 - The connection is repaired
XmemNozzle14:30:08.419887 [INFO] xmem_127.0.0.1:12000_0 - The unresponded items are resent
XmemNozzle14:30:08.419915 [ERROR] xmem_127.0.0.1:12000_0 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.419923 [INFO] xmem_127.0.0.1:12000_0 connection is broken, try to repair...
XmemNozzle14:30:08.419939 [INFO] xmem_127.0.0.1:12000_0 - The connection is repaired
XmemNozzle14:30:08.419995 [ERROR] xmem_127.0.0.1:12000_0 sendSingle: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.429414 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.429427 [INFO] init a new batch
XmemNozzle14:30:08.429431 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 1 batches ready
XmemNozzle14:30:08.435810 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.435833 [INFO] init a new batch
XmemNozzle14:30:08.435843 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 1 batches ready
XmemNozzle14:30:08.435850 [INFO] Send batch count=500
XmemNozzle14:30:08.435967 [ERROR] xmem_127.0.0.1:12000_1 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.435975 [INFO] xmem_127.0.0.1:12000_1 connection is broken, try to repair...
XmemNozzle14:30:08.436000 [INFO] xmem_127.0.0.1:12000_1 - The connection is repaired
XmemNozzle14:30:08.436540 [INFO] xmem_127.0.0.1:12000_1 - The unresponded items are resent
XmemNozzle14:30:08.436563 [ERROR] xmem_127.0.0.1:12000_1 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.436569 [INFO] xmem_127.0.0.1:12000_1 connection is broken, try to repair...
XmemNozzle14:30:08.436580 [INFO] xmem_127.0.0.1:12000_1 - The connection is repaired
XmemNozzle14:30:08.437498 [INFO] xmem_127.0.0.1:12000_1 - The unresponded items are resent
XmemNozzle14:30:08.437527 [ERROR] xmem_127.0.0.1:12000_1 batchSend: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:08.437535 [INFO] xmem_127.0.0.1:12000_1 connection is broken, try to repair...
XmemNozzle14:30:08.437550 [INFO] xmem_127.0.0.1:12000_1 - The connection is repaired
XmemNozzle14:30:08.437615 [ERROR] xmem_127.0.0.1:12000_1 sendSingle: transmit error: write tcp 127.0.0.1:12000: connection reset by peer
XmemNozzle14:30:08.445744 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.445757 [INFO] init a new batch
XmemNozzle14:30:08.445761 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 2 batches ready
XmemNozzle14:30:08.451096 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.451110 [INFO] init a new batch
XmemNozzle14:30:08.451116 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 1 batches ready
XmemNozzle14:30:08.462003 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.462018 [INFO] init a new batch
XmemNozzle14:30:08.462026 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 3 batches ready
XmemNozzle14:30:08.465912 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.465921 [INFO] init a new batch
XmemNozzle14:30:08.465927 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 2 batches ready
XmemNozzle14:30:08.473803 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.473819 [INFO] init a new batch
XmemNozzle14:30:08.473825 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 4 batches ready
XmemNozzle14:30:08.476426 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.476434 [INFO] init a new batch
XmemNozzle14:30:08.476438 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 3 batches ready
XmemNozzle14:30:08.492647 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.492666 [INFO] init a new batch
XmemNozzle14:30:08.492677 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 5 batches ready
XmemNozzle14:30:08.492857 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.492866 [INFO] init a new batch
XmemNozzle14:30:08.492872 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 4 batches ready
XmemNozzle14:30:08.509287 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.509303 [INFO] init a new batch
XmemNozzle14:30:08.509310 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 6 batches ready
XmemNozzle14:30:08.509490 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.509498 [INFO] init a new batch
XmemNozzle14:30:08.509504 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 5 batches ready
XmemNozzle14:30:08.522248 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.522268 [INFO] init a new batch
XmemNozzle14:30:08.522275 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 7 batches ready
XmemNozzle14:30:08.522464 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.522473 [INFO] init a new batch
XmemNozzle14:30:08.522479 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 6 batches ready
XmemNozzle14:30:08.537511 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.537536 [INFO] init a new batch
XmemNozzle14:30:08.537542 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 8 batches ready
XmemNozzle14:30:08.537740 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.537749 [INFO] init a new batch
XmemNozzle14:30:08.537755 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 7 batches ready
XmemNozzle14:30:08.549348 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=500) ready queue
XmemNozzle14:30:08.549363 [INFO] init a new batch
XmemNozzle14:30:08.549370 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 9 batches ready
XmemNozzle14:30:08.549465 [INFO] xmem_127.0.0.1:12000_1 move the batch (count=500) ready queue
XmemNozzle14:30:08.549469 [INFO] init a new batch
XmemNozzle14:30:08.549472 [INFO] xmem_127.0.0.1:12000_1 End moving batch, 8 batches ready
XmemNozzle14:30:08.894274 [ERROR] xmem_127.0.0.1:12000_1 sendSingle: transmit error: write tcp 127.0.0.1:12000: broken pipe
XmemNozzle14:30:09.294250 [INFO] xmem_127.0.0.1:12000_0 batch expired, moving it to ready queue
XmemNozzle14:30:09.294279 [INFO] xmem_127.0.0.1:12000_0 move the batch (count=38) ready queue
XmemNozzle14:30:09.294287 [INFO] init a new batch
XmemNozzle14:30:09.294293 [INFO] xmem_127.0.0.1:12000_0 End moving batch, 10 batches ready
XmemNozzle14:30:21.294472 [ERROR] xmem_127.0.0.1:12000_0 sendSingle: transmit error: write tcp 127.0.0.1:12000: broken pipe

****Hangs******************

Attaching screenshot of dcp drain queue for source 'default' bucket. Default bucket had 10000 keys.

 Comments   
Comment by Aruna Piravi [ 25/Nov/14 ]
Workaround: restart xdcr rest server, drop and recreate replication, replication happens.
Comment by Xiaomei Zhang [ 25/Nov/14 ]
Aruna,

Is this the same as MB-12771?

Thanks,
-Xiaomei
Comment by Aruna Piravi [ 25/Nov/14 ]
No Xiaomei, I've never seen "sendSingle: transmit error: write tcp IP:12000: broken pipe" error message while recreating replication on recreated target buckets.

In my opinion, this bug is due to transmit error but the pipeline does get created as you can see above. However with MB-12771 even pipeline doesn't get created(as you see in the log).




[MB-12769] run millis_to_str(str_to_millis(some_date)) do not give right result Created: 25/Nov/14  Updated: 26/Nov/14

Status: Reopened
Project: Couchbase Server
Component/s: query
Affects Version/s: sherlock
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
query is:
 select join_yr, join_mo, join_day, millis_to_str(str_to_millis(tostr(join_yr) || '-0' || tostr(join_mo) || '-0' || tostr(join_day))) as date from default where join_mo < 10 and join_day < 10 ORDER BY date asc

but results for example for millis_to_str(str_to_millis('2010-01-01')) is 2009-12-31

query result starts as:
[{'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}, {'date': u'2009-12-31', 'join_yr': 2010, 'join_mo': 1, 'join_day': 1}

 Comments   
Comment by Gerald Sangudi [ 25/Nov/14 ]
Default to local time zone.
Comment by Iryna Mironava [ 25/Nov/14 ]
how does n1ql know then the zone?
if i do str_to_millis('2010-01-01') -> i get some <value> according to local zone of the machine
but if i convert this value millis_to_str(<value>) i get one day less. But it is same machine and local zone is not changed. Could you please explain what i am doing wrong?
Comment by Gerald Sangudi [ 25/Nov/14 ]
can you post the queries and results?
Comment by Ketaki Gangal [ 26/Nov/14 ]
Hi Gerald,

The above looks like a bug behaviour. Could you explain why this is dependent on any timezone not classified as a bug?
Comment by Gerald Sangudi [ 26/Nov/14 ]
Hi Ketaki,

Jan 1 at 1:30am in New York is Dec 31 at 10:30pm in Los Angeles. I need to see the exact query and results to determine if it's a bug.

Thanks.
Comment by Iryna Mironava [ 26/Nov/14 ]
query is select millis_to_str(str_to_millis('2010-01-01')) as date
result is
{u'status': u'success', u'metrics': {u'elapsedTime': u'1.685069ms', u'executionTime': u'1.54437ms', u'resultSize': 59, u'resultCount': 1}, u'signature': {u'date': u'string'}, u'results': [{u'date': u'2009-12-31T16:00:00-08:00'}], u'request_id': u'7b22fbdc-1f4b-4f13-8ef5-e9aab67f19cb'}

as i do both str_to_millis and millis_to_str at the same time, i expect my date to be same as initial - '2010-01-01' but it is 2009-12-31T16:00:00-08:00

this was a jenkins run http://qa.sc.couchbase.com/job/centos_x64--52_00--n1ql_tests-P0/21/consoleFull




[MB-12768] cbbackupwrapper does not display the '-x' extra parameters Created: 25/Nov/14  Updated: 26/Nov/14  Resolved: 26/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: tools
Affects Version/s: 3.0.2
Fix Version/s: 3.0.2
Security Level: Public

Type: Bug Priority: Critical
Reporter: Ashvinder Singh Assignee: Bin Cui
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment: All OSes

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
Found on build: 3.0.2-1565

cbbackupwrapper -h does not display the complete options as are displayed in 'cbbackup' tool. The 'cbbackupwrapper' shows '-x' but does not display what options can be supplied with '-x' option.

Current output from cbbackupwrapper:
Usage: cbbackupwrapper CLUSTER BACKUPDIR OPTIONS

Options:
  -h, --help show this help message and exit
  -b BUCKET_SOURCE, --bucket-source=BUCKET_SOURCE
                        Specify the bucket to backup. Defaults to all buckets
  --single-node use a single server node from the source only
  -u USERNAME, --username=USERNAME
                        REST username for source cluster or server node.
                        Default is Administrator
  -p PASSWORD, --password=PASSWORD
                        REST password for source cluster or server node.
                        Defaults to PASSWORD
  -v, --verbose Enable verbose messaging
  --path=PATH Specify the path to cbbackup. Defaults to current
                        directory
  --port=PORT Specify the bucket port. Defaults to 11210
  -n NUMBER, --number=NUMBER
                        Specify the number of vbuckets per process. Defaults
                        to 100
  -x EXTRA, --extra=EXTRA
                        Provide extra, uncommon config parameters;
                        comma-separated key=val(,key=val)* pairs
  -m MODE, --mode=MODE backup mode: full, diff or accu [default:diff]

 Comments   
Comment by Bin Cui [ 26/Nov/14 ]
http://review.couchbase.org/#/c/43649/




[MB-12767] cbbackup wrapper throws warning when executed Created: 25/Nov/14  Updated: 26/Nov/14  Resolved: 26/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: tools
Affects Version/s: 3.0.2
Fix Version/s: 3.0.2
Security Level: Public

Type: Bug Priority: Critical
Reporter: Ashvinder Singh Assignee: Bin Cui
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment: All OSes

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
Found on build: 3.0.2-1565

Steps to reproduce:
- Install Build and setup server with data using cbworkload gen
- run /opt/couchbase/bin/cbbackwrapper cbbackupwrapper http://172.23.106.71:8091 /tmp/backup -u Administrator -p password -x

The output:
>>>>>>>>>>>>>>>>

WARN: Could not find name for nodeip
Waiting for the backup to complete...
SUCCESSFULLY COMPLETED!

<<<<<<<<<<

Expectation: No warning should be present.

 Comments   
Comment by Bin Cui [ 26/Nov/14 ]
http://review.couchbase.org/#/c/43648/




[MB-12766] subqueries fail with error Error doing bulk get Created: 25/Nov/14  Updated: 25/Nov/14  Due: 01/Dec/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4, sherlock
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Manik Taneja
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 8h
Time Spent: Not Specified
Original Estimate: 8h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
query
select name, join_day from default where join_day = (select AVG(join_day) as average from default d use keys ['query-test-Sales-0', 'query-test-Sales-1', 'query-test-Sales-2', 'query-test-Sales-3', 'query-test-Sales-4', 'query-test-Sales-5'])[0].average

{
    "request_id": "d1ed4e07-3841-41d0-8465-5187f799a40b",
    "signature": {
        "join_day": "json",
        "name": "json"
    },
    "results": [
    ]
    "errors": [
        {
            "caller": "couchbase:492",
            "cause": "{3 errors, starting with bulkget exceeded MaxBulkRetries for vbucket 755}",
            "code": 5000,
            "key": "Internal Error",
            "message": "Error doing bulk get"
        },
        {
            "caller": "couchbase:492",
            "cause": "{1 errors, starting with bulkget exceeded MaxBulkRetries for vbucket 1018}",
            "code": 5000,
            "key": "Internal Error",
            "message": "Error doing bulk get"
        },
        {
            "caller": "couchbase:492",
            "cause": "{1 errors, starting with bulkget exceeded MaxBulkRetries for vbucket 253}",
            "code": 5000,
            "key": "Internal Error",
            "message": "Error doing bulk get"
        }
    ],
    "status": "errors",
    "metrics": {
        "elapsedTime": "3m1.147069007s",
        "executionTime": "3m1.14694197s",
        "resultCount": 0,
        "resultSize": 0,
        "errorCount": 3
    }
}





[MB-12765] meta() shows incorrect cas value Created: 25/Nov/14  Updated: 25/Nov/14  Due: 28/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Manik Taneja
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 4h
Time Spent: Not Specified
Original Estimate: 4h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
item has key 'query-test67f75c3-0'
if try to get cas via sdk it is 28686505813123738

client.get(key.encode('utf-8'))
tuple: (4042322160, 28686505813123738, '{"tasks_points": {"task1": 1, "task2": 1}, "name": "employee-28", "mutated": 0, "skills": ["skill2010", "skill2011"], "join_day": 28, "join_mo": 10, "email": "28-mail@couchbase.com", "test_rate": 10.1, "join_yr": 2011, "_id": "query-test67f75c3-0", "VMs": [{"RAM": 10, "os": "ubuntu", "name": "vm_10", "memory": 10}, {"RAM": 10, "os": "windows", "name": "vm_11", "memory": 10}], "job_title": "Engineer"}')

but if i try to get cas via n1ql it is 28686505813123736
cbq> select META(default) from default use keys ['query-test67f75c3-0']
   > ;
{
    "request_id": "e15c93f7-ad42-4ad7-9d99-d443b9b19427",
    "signature": {
        "$1": "object"
    },
    "results": [
        {
            "$1": {
                "cas": 2.8686505813123736e+16,
                "flags": 4.04232216e+09,
                "id": "query-test67f75c3-0",
                "type": "json"
            }
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "57.992ms",
        "executionTime": "57.866ms",
        "resultCount": 1,
        "resultSize": 209
    }
}





[MB-12764] latest n1ql + 3.0.0 after reload bucket queries hang Created: 25/Nov/14  Updated: 26/Nov/14  Due: 26/Nov/14  Resolved: 25/Nov/14

Status: Closed
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Test Blocker
Reporter: Iryna Mironava Assignee: Manik Taneja
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: 8h
Time Spent: Not Specified
Original Estimate: 8h

Triage: Untriaged
Is this a Regression?: Yes

 Description   
1) create a bucket
2) start cbq-engine and create primary index
3) recreate the bucket
4) restart cbq-engine
5) when try to query this bucket query hang, there no any output in cbq
in cbq-engine see logs like
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:06+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Refreshing pool default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Checking keyspace default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Created New Bucket default"
_time="2014-11-25T20:18:07+04:00" _level="INFO" _msg=" Refreshing pool default"

 Comments   
Comment by Manik Taneja [ 25/Nov/14 ]
this happened due to a regression after commit :
90059ee7a043280223573f409811064e2de8af98

Reverted those commits and this bug has gone away.
Comment by Iryna Mironava [ 26/Nov/14 ]
verified




[MB-12763] large body length value causes moxi to restart Created: 25/Nov/14  Updated: 25/Nov/14

Status: Open
Project: Couchbase Server
Component/s: moxi
Affects Version/s: 3.0.1
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Minor
Reporter: Ian McCloy Assignee: Steve Yen
Resolution: Unresolved Votes: 0
Labels: security
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
Memcached has a bug CVE-2011-4971,

"Multiple integer signedness errors in the (1) process_bin_sasl_auth, (2) process_bin_complete_sasl_auth, (3) process_bin_update, and (4) process_bin_append_prepend functions in Memcached 1.4.5 and earlier allow remote attackers to cause a denial of service (crash) via a large body length value in a packet."

I tried this out on CB Server 3.0.1, it causes Moxi to restart but didn't seem to interrupt operations or cause a need to warmup the cache. Is Moxi restarting a concern ?

Steps to reproduce:

echo -en '\x80\x12\x00\x01\x08\x00\x00\x00\xff\xff\xff\xe8\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xff\xff\xff\xff\x01\x00\x00\x00\x00\x00\x00\x00\x00\x000\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' | nc localhost 11211

Result:

Port server moxi on node 'babysitter_of_ns_1@127.0.0.1' exited with status 139. Restarting. Messages: 2014-11-25 13:50:47: (/home/buildbot/buildbot_slave/debian-7-x64-301-builder/build/build/moxi/src/cproxy_config.c.327) env: MOXI_SASL_PLAIN_USR (1)
2014-11-25 13:50:47: (/home/buildbot/buildbot_slave/debian-7-x64-301-builder/build/build/moxi/src/cproxy_config.c.336) env: MOXI_SASL_PLAIN_PWD (32)

 Comments   
Comment by Ian McCloy [ 25/Nov/14 ]
https://code.google.com/p/memcached/issues/detail?id=192 < Original Memcached bug and simple patch / fix
Comment by Ian McCloy [ 25/Nov/14 ]
Same command on memcached port gives back a sensible error message

echo -en '\x80\x12\x00\x01\x08\x00\x00\x00\xff\xff\xff\xe8\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\xff\xff\xff\xff\x01\x00\x00\x00\x00\x00\x00\x00\x00\x000\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00' | nc localhost 11210

� Too large




[MB-12762] Memcached consuming ~100% CPU resources Created: 25/Nov/14  Updated: 25/Nov/14  Resolved: 25/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: memcached
Affects Version/s: 3.0.1, 3.0
Fix Version/s: 3.0.2
Security Level: Public

Type: Bug Priority: Major
Reporter: Abhishek Singh Assignee: Raju Suravarjjala
Resolution: Fixed Votes: 0
Labels: security
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: PNG File top-output.png    
Triage: Untriaged
Operating System: Centos 64-bit
Is this a Regression?: Unknown

 Description   
If 'echo "a" | nc -w 1 10.4.2.106 11207' is fired against a 3.x couchbase server, memcached starts using ~100% CPU resources. 11207 is used for SSL communication between CB node and client. Screenshot attached

 Comments   
Comment by Dave Rigby [ 25/Nov/14 ]
Reproduced. The issue is that if the a client disconnects before SSL negotiation has completed then memcached fails to reset that connection, and instead keeps on waiting on data to read.

This doesn't prevent other clients (SSL or non-SSL) from connecting, or their requests from being served. The 100% side of things is essentially the internal event loop repeatedly trying to read data from the should-be closed connection.
Comment by Dave Rigby [ 25/Nov/14 ]
Fix http://review.couchbase.org/#/c/43604/ merged to master.
Comment by Anil Kumar [ 25/Nov/14 ]
Dave - Can you merge the changes to 3.0.2 today. We will be cutting a RC build tomorrow.
Comment by Dave Rigby [ 25/Nov/14 ]
Anil - The backport is up on gerrit at: http://review.couchbase.org/#/c/43608/ but I don't appear to be able to submit it - maybe there's additional lockdown on memcached/3.0?

If you can find someone who has the appropriate powers please submit it; otherwise it'll have to wait for Trond tomorrow.
Comment by Chris Hillery [ 25/Nov/14 ]
FYI, this submission broke the build: MB-12774




[MB-12761] The server doesn't support ASCII protocol unless moxi is running Created: 25/Nov/14  Updated: 26/Nov/14

Status: Open
Project: Couchbase Server
Component/s: UI
Affects Version/s: sherlock
Fix Version/s: None
Security Level: Public

Type: Task Priority: Major
Reporter: Trond Norbye Assignee: Aleksey Kondratenko
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: PNG File Couchbase_Console__3_0_0-1156_.png    

 Description   
Running Couchbase server as of 24 November moxi isn't enabled by default, but if you try to modify a bucket you're displayed the attached screenshot. The following things is wrong:

1) ASCII protocol is _only_ supported through moxi
2) The preferred port for our system is 11210, which is the data port only supporting the binary protocol. Using 11211 will cause an extra network hop between moxi and memcached.
3) A dedicated port is only supported through moxi




 Comments   
Comment by Matt Ingenthron [ 25/Nov/14 ]
I believe I filed a bug on this previously. In that bug, I mentioned the UI indicates moxi and SASL auth are mutually exclusive, but that's not our implementation IIRC. Perhaps going into Sherlock we should consider moxi like all of the other "services" at the UI/configuration level?
Comment by Trond Norbye [ 26/Nov/14 ]
Matt: In sherlock moxi is a service you can enable during the configuration phase and it's by default off (YAY!!!!)




[MB-12760] Go-XDCR: ErrorNoSourceNozzle thrown from xdcr_factory.go at the start of replication Created: 24/Nov/14  Updated: 25/Nov/14  Resolved: 25/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: cross-datacenter-replication
Affects Version/s: sherlock
Fix Version/s: sherlock
Security Level: Public

Type: Bug Priority: Critical
Reporter: Aruna Piravi Assignee: Xiaomei Zhang
Resolution: Cannot Reproduce Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Epic Link: XDCR next release
Is this a Regression?: Yes

 Description   
Pulled in latest code, compiled and created replication.

AdminPort18:06:47.257573 [INFO] Request with path, /controller/createReplication, method, POST, and content type application/x-www-form-urlencoded
AdminPort18:06:47.257591 [INFO] handleRequest called
AdminPort18:06:47.257679 [INFO] Request: &{POST /controller/createReplication HTTP/1.1 1 1 map[Content-Length:[79] Content-Type:[application/x-www-form-urlencoded] User-Agent:[curl/7.30.0] Accept:[*/*]] 0xc208086100 79 [] false localhost:12160 map[] map[] <nil> map[] 127.0.0.1:50234 /controller/createReplication <nil>}
AdminPort18:06:47.257691 [INFO] Request key decoded: controller/createReplication/POST
AdminPort18:06:47.257696 [INFO] doCreateReplicationRequest called
ReplicationManager18:06:47.257778 [INFO] Creating replication - sourceCluterUUID=127.0.0.1:9000, sourceBucket=default, targetClusterUUID=localhost:9000, targetBucket=target, filterName=, settings=map[batch_count:500 active:true target_nozzle_per_node:2 max_expected_replication_lag:1000 timeout_percentage_cap:80 checkpoint_interval:1800 filter_expression: optimistic_replication_threshold:256 failure_restart_interval:30 batch_size:2048 http_connection:20 source_nozzle_per_node:2 replication_type:xmem log_level:Info], createReplSpec=true
ReplicationManager18:06:47.257809 [INFO] Creating replication spec - sourceCluterUUID=127.0.0.1:9000, sourceBucket=default, targetClusterUUID=localhost:9000, targetBucket=target, filterName=, settings=map[active:true target_nozzle_per_node:2 batch_count:500 max_expected_replication_lag:1000 timeout_percentage_cap:80 optimistic_replication_threshold:256 failure_restart_interval:30 checkpoint_interval:1800 filter_expression: source_nozzle_per_node:2 replication_type:xmem log_level:Info batch_size:2048 http_connection:20]
ReplicationManager18:06:47.301738 [INFO] Pipeline xdcr_127.0.0.1:9000_default_localhost:9000_target is created and started
AdminPort18:06:47.301752 [INFO] forwardReplicationRequest
PipelineManager18:06:47.301797 [INFO] Starting the pipeline xdcr_127.0.0.1:9000_default_localhost:9000_target
XDCRFactory18:06:47.302111 [INFO] kvHosts=[127.0.0.1]
cluster=127.0.0.1:9000
ServerList=[10.17.2.125:12000]
ServerVBMap=map[10.17.2.125:12000:[0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390 391 392 393 394 395 396 397 398 399 400 401 402 403 404 405 406 407 408 409 410 411 412 413 414 415 416 417 418 419 420 421 422 423 424 425 426 427 428 429 430 431 432 433 434 435 436 437 438 439 440 441 442 443 444 445 446 447 448 449 450 451 452 453 454 455 456 457 458 459 460 461 462 463 464 465 466 467 468 469 470 471 472 473 474 475 476 477 478 479 480 481 482 483 484 485 486 487 488 489 490 491 492 493 494 495 496 497 498 499 500 501 502 503 504 505 506 507 508 509 510 511 512 513 514 515 516 517 518 519 520 521 522 523 524 525 526 527 528 529 530 531 532 533 534 535 536 537 538 539 540 541 542 543 544 545 546 547 548 549 550 551 552 553 554 555 556 557 558 559 560 561 562 563 564 565 566 567 568 569 570 571 572 573 574 575 576 577 578 579 580 581 582 583 584 585 586 587 588 589 590 591 592 593 594 595 596 597 598 599 600 601 602 603 604 605 606 607 608 609 610 611 612 613 614 615 616 617 618 619 620 621 622 623 624 625 626 627 628 629 630 631 632 633 634 635 636 637 638 639 640 641 642 643 644 645 646 647 648 649 650 651 652 653 654 655 656 657 658 659 660 661 662 663 664 665 666 667 668 669 670 671 672 673 674 675 676 677 678 679 680 681 682 683 684 685 686 687 688 689 690 691 692 693 694 695 696 697 698 699 700 701 702 703 704 705 706 707 708 709 710 711 712 713 714 715 716 717 718 719 720 721 722 723 724 725 726 727 728 729 730 731 732 733 734 735 736 737 738 739 740 741 742 743 744 745 746 747 748 749 750 751 752 753 754 755 756 757 758 759 760 761 762 763 764 765 766 767 768 769 770 771 772 773 774 775 776 777 778 779 780 781 782 783 784 785 786 787 788 789 790 791 792 793 794 795 796 797 798 799 800 801 802 803 804 805 806 807 808 809 810 811 812 813 814 815 816 817 818 819 820 821 822 823 824 825 826 827 828 829 830 831 832 833 834 835 836 837 838 839 840 841 842 843 844 845 846 847 848 849 850 851 852 853 854 855 856 857 858 859 860 861 862 863 864 865 866 867 868 869 870 871 872 873 874 875 876 877 878 879 880 881 882 883 884 885 886 887 888 889 890 891 892 893 894 895 896 897 898 899 900 901 902 903 904 905 906 907 908 909 910 911 912 913 914 915 916 917 918 919 920 921 922 923 924 925 926 927 928 929 930 931 932 933 934 935 936 937 938 939 940 941 942 943 944 945 946 947 948 949 950 951 952 953 954 955 956 957 958 959 960 961 962 963 964 965 966 967 968 969 970 971 972 973 974 975 976 977 978 979 980 981 982 983 984 985 986 987 988 989 990 991 992 993 994 995 996 997 998 999 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023]]
XDCRFactory18:06:47.338839 [INFO] Constructed 0 source nozzles
PipelineManager18:06:47.338846 [ERROR]Failed to construct a new pipeline: Invalid configuration. No source nozzle can be constructed since the source kv nodes are not the master for any vbuckets.

 Comments   
Comment by Xiaomei Zhang [ 25/Nov/14 ]
Aruna,

I did the following to reproduce the issue you reported.
1. repo sync
2. make
3. >cd ns_server
4. >export COUCHBASE_NUM_VBUCKETS=64
5. >make dataclean
6. >./cluster_run
7. import beer-sample bucket, and configure default bucket on admin console
8. >cd <sherlock repo dir>/install/bin
9. > ./goxdcr
10. > curl -X POST http://127.0.0.1:12100/controller/createReplication -d fromBucket=beer-sample -d uuid=127.0.0.1:9000 -d toBucket=default -d xdcrLogLevel=Debug

It works fine, 7303 document is replicated from beer-sample to default. What did I miss here?




[MB-12758] Incorrect resutls from "ifnull" Created: 24/Nov/14  Updated: 25/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4, 3.0, sherlock
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Critical
Reporter: Ketaki Gangal Assignee: Isha Kandaswamy
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 4h
Time Spent: Not Specified
Original Estimate: 4h

Triage: Untriaged
Is this a Regression?: Yes

 Description   
Regression runs on 3.5.0-365-rel shows errors on result mismatch on ifNull

test to run : https://github.com/couchbase/testrunner/blob/master/conf/tuq/py-tuq-nulls.conf#L11

======================================================================
FAIL: test_ifnull (tuqquery.tuq_nulls.NULLTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "pytests/tuqquery/tuq_nulls.py", line 187, in test_ifnull
    self._verify_results(actual_result['results'], expected_result)
  File "pytests/tuqquery/tuq.py", line 2558, in _verify_results
    expected_result[:100],expected_result[-100:]))
AssertionError: Results are incorrect.

 Actual first and last 100: [{u'feature_name': u'0', u'point': 3}, {u'feature_name': u'1', u'point': 3}, {u'feature_name': u'10', u'point': 3}, {u'feature_name': u'100', u'point': 3}, {u'feature_name': u'101', u'point': 3}, {u'feature_name': u'102', u'point': 3}, {u'feature_name': u'103', u'point': 3}, {u'feature_name': u'104', u'point': 3}, {u'feature_name': u'105', u'point': 3}, {u'feature_name': u'106', u'point': 3}, {u'feature_name': u'107', u'point': 3}, {u'feature_name': u'108', u'point': 3}, {u'feature_name': u'109', u'point': 3}, {u'feature_name': u'11', u'point': 3}, {u'feature_name': u'110', u'point': 3}, {u'feature_name': u'111', u'point': 3}, {u'feature_name': u'112', u'point': 3}, {u'feature_name':

 Comments   
Comment by Iryna Mironava [ 25/Nov/14 ]
the issue is that we see results like
{u\'feature_name\': u\'987\', u\'point\': None}, {u\'feature_name\': u\'988\', u\'point\': None}, {u\'feature_name\': u\'989\', u\'point\': None}, {u\'feature_name\': u\'99\', u\'point\': 3}, {u\'feature_name\': u\'990\', u\'point\': None}, {u\'feature_name\': u\'991\', u\'point\': None}, {u\'feature_name\': u\'992\', u\'point\': None}, {u\'feature_name\': u\'993\', u\'point\': None}, {u\'feature_name\': u\'994\', u\'point\': None}, {u\'feature_name\': u\'995\', u\'point\': None}, {u\'feature_name\': u\'996\', u\'point\': None}, {u\'feature_name\': u\'997\', u\'point\': None}, {u\'feature_name\': u\'998\', u\'point\': None}, {u\'feature_name\': u\'999\', u\'point\': None}
documentation says
IFNULL(expr1, expr2, ...) - first non-NULL value. Note that this function may return MISSING.
so i would expect to see results like {u\'feature_name\': u\'999\'}
Comment by Gerald Sangudi [ 25/Nov/14 ]
Isha,

Please work with Ketaki and Iryna to troubleshoot this.

Thanks.




[MB-12757] Indexes are not selected during a query on indexed attribute Created: 24/Nov/14  Updated: 24/Nov/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: 3.0, sherlock
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Critical
Reporter: Ketaki Gangal Assignee: Gerald Sangudi
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
1. Create a primary index
2. Create a index(city) on a bucket
3. Query on city_index, expect Query to be using city_index, instead it defaults to primary index.

create index city_idx on `123ab`(city);
cbq> EXPLAIN select * from `123ab` where city="$str5";
{
    "request_id": "5220bc2a-3382-4bd2-8343-d609a3b8c09e",
    "signature": "json",
    "results": [
        {
            "children": [
                {
                    "index": "#primary",
                    "type": "primaryScan"
                },
                {
                    "children": {
                        "children": [
                            {
                                "as": "123ab",
                                "keyspace": "123ab",
                                "type": "fetch"
                            },
                            {
                                "condition": "((`123ab`.`city`) = \"$str5\")",
                                "type": "where"
                            },
                            {
                                "projection": {
                                    "distinct": false,
                                    "raw": false,
                                    "terms": [
                                        {
                                            "alias": "",
                                            "as": "",
                                            "star": true,
                                            "type": "resultTerm"
                                        }
                                    ],
                                    "type": "projection"
                                },
                                "terms": [
                                    {
                                        "result": {
                                            "alias": "",
                                            "as": "",
                                            "star": true,
                                            "type": "resultTerm"
                                        },
                                        "type": "resultProject"
                                    }
                                ],
                                "type": "initialProject"
                            },
                            {
                                "type": "finalProject"
                            }
                        ],
                        "type": "serial"
                    },
                    "type": "parallel"
                }
            ],
            "type": "serial"
        }
    ],
    "state": "success",
    "metrics": {
        "elapsedTime": "65.550425ms",
        "executionTime": "65.079558ms",
        "resultCount": 1,
        "resultSize": 2265
    }
}


@gerald : If this is an open Dev task, please feel free to close this.

But a lot of QE-tests currently fail due to index selection defaulting to primary, whereas the test-logic expects it to be a particular index instead.

Reference : http://qa.sc.couchbase.com/job/centos_x64--52_00--n1ql_tests-P0/13/




[MB-12756] Query/N1QL: Syntax error if bucket name begins with a number Created: 24/Nov/14  Updated: 24/Nov/14  Resolved: 24/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: query
Affects Version/s: 3.0.1
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Brian Williams Assignee: Gerald Sangudi
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
Steps to reproduce

1. Create a bucket whose name begins with a number such as "1bucket"

2. Open cbq

3. Confirm the bucket exists with

SELECT * from :system.buckets'

4. Attempt to use a query which refers to that bucket, such as:

CREATE PRIMARY INDEX on 1bucket;

or

SELECT * from 1bucket;

5. Observe the following error

{
    "error":
        {
            "caller": "standard:50",
            "cause": "Parse Error - syntax error",
            "code": 4100,
            "key": "parse_error",
            "message": "Parse Error"
        }
}


 Comments   
Comment by Gerald Sangudi [ 24/Nov/14 ]
Use back ticks:

CREATE PRIMARY INDEX on `1bucket`;

or

SELECT * from `1bucket`;




[MB-12755] since a subquery is an array, should i be able to run ARRAY_LENGTH? Created: 24/Nov/14  Updated: 24/Nov/14  Resolved: 24/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Iryna Mironava
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
for example:
select ARRAY_LENGTH(select VMs from default d use keys ['query-test00066b1-0', 'query-test00066b1-1']) as num, name from default;
should it work?

 Comments   
Comment by Gerald Sangudi [ 24/Nov/14 ]
Need 2 parens: one for the function, one for the subquery:

select ARRAY_LENGTH((select VMs from default d use keys ['query-test00066b1-0', 'query-test00066b1-1'])) as num, name from default;




[MB-12754] Support auto commit option for asynchronous write Created: 24/Nov/14  Updated: 24/Nov/14

Status: Open
Project: Couchbase Server
Component/s: forestdb
Affects Version/s: feature-backlog
Fix Version/s: feature-backlog
Security Level: Public

Type: Improvement Priority: Minor
Reporter: Jung-Sang Ahn Assignee: Jung-Sang Ahn
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   
For users who do not want strict synchronous write, calling fsync() is not necessary but fdb_commit() should be invoked periodically in ForestDB, to flush WAL entries and to append DB header.

It is uncomfortable for users to determine when to call fdb_commit() between consecutive fdb_set() calls. If they call fdb_commit() per each fdb_set(), ForestDB will show the worst performance and the largest write amplification. By contrast, if fdb_commit() is invoked only once after a number of fdb_set() calls, WAL restore procedure will take long time to reconstruct WAL entries when we reopen the DB file.

The best timing to call fdb_commit() is when WAL becomes full (i.e., the number of WAL entries reaches the configured threshold). We can (almost) minimize the write amplification and maximize the write throughput, while restoring WAL entries takes very short time.

Hence, for asynchronous write mode, we need to add an option called 'auto_commit' which is similar to the existing 'wal_flush_before_commit' option. With the auto commit option, when fdb_set() is called and WAL becomes full, fdb_commit() is automatically called so that users do not need to manually call it.






[MB-12753] div() has to be integer quotient of y/x, but result shows a float Created: 24/Nov/14  Updated: 24/Nov/14  Resolved: 24/Nov/14

Status: Closed
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
expected is 2, but result is 2.25

cbq> select div(9,4);
{
    "request_id": "fe54807c-b9b3-4dcd-98d3-93bb6dce404c",
    "signature": {
        "$1": "number"
    },
    "results": [
        {
            "$1": 2.25
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "1.179ms",
        "executionTime": "1.097ms",
        "resultCount": 1,
        "resultSize": 34
    }
}

cbq>


 Comments   
Comment by Gerald Sangudi [ 24/Nov/14 ]
Hi Iryna,

In the spec, we removed the DIV() function.

Users should use TRUNC() to get the integer result.

Thanks.




[MB-12752] Couchbase 3.0.1 performance issue in full metadata ejection mode Created: 24/Nov/14  Updated: 24/Nov/14

Status: Open
Project: Couchbase Server
Component/s: None
Affects Version/s: 3.0.1
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: hwe Assignee: Chiyoung Seo
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment: I use 2 Clients with 32 Threads for inserting and the Cluster has 2 Nodes.
The hardware specs for clients and cluster nodes are identical:
Dell PowerEdge C62202 with
- 2 Intel Xeon E5-2609 (each 4 Cores)
- 32 GB RAM
- 4 x 1 TB SATA 7.2 k
- Ubuntu 12.04 LTS

Cluster Nodes only:
- sysctl vm.swappiness=0
- echo never > /sys/kernel/mm/transparent_hugepage/defrag\
- /sys/kernel/mm/transparent_hugepage/enabled\
- Oracle JDK 1.7.0_72-b14

Client only:
- OpenJDK 1.6.0_32

Attachments: Zip Archive client logs.zip     PNG File ops per second.png     PNG File resident.png     PNG File summary.png     GZip Archive ycsb couchbase 3 db adapter.tar.gz    
Triage: Untriaged
Link to Log File, atop/blg, CBCollectInfo, Core dump: CBCollectInfo uploaded to https://s3.amazonaws.com/customers.couchbase.com/hwe@h-da/
 - gulltown.zip
 - runestone.zip
Is this a Regression?: Unknown

 Description   
At the moment I'm doing some tests with couchbase 3.0.1 community edition and the java sdk 2.0.1. In full metadata ejection mode the performance drops after approximately 100 million inserts. In contrast, the value ejection mode performs 200 million inserts without problems.

My code is based on the thumbtack ycsb version (https://github.com/thumbtack-technology/ycsb), but i added new DB adapter (based on java sdk 2.0.1).

See more in https://forums.couchbase.com/t/couchbase-3-0-1-performance-issue-in-full-metadata-ejection-mode

 Comments   
Comment by Matt Ingenthron [ 24/Nov/14 ]
Thanks for filing the issue and all of the info @hwe. Much appreciated.
Comment by Matt Ingenthron [ 24/Nov/14 ]
Chiyoung: Assigning this to you as you'll know where to take it from here. It may be related to MB-10291.




[MB-12751] Replace on a locked doc gives Key not found error Created: 24/Nov/14  Updated: 26/Nov/14  Resolved: 26/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: couchbase-bucket
Affects Version/s: 3.0.1
Fix Version/s: sherlock, 3.0.2
Security Level: Public

Type: Bug Priority: Major
Reporter: Ian McCloy Assignee: Trond Norbye
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment: CB Server 3.0.1

$ pip list | grep couchbase
couchbase (1.2.4)
$ rpm -qa | grep couchbase
libcouchbase2-core-2.4.3-1.el6.x86_64
couchbase-server-3.0.1-1444.x86_64
libcouchbase-devel-2.4.3-1.el6.x86_64

Issue Links:
Dependency
Triage: Untriaged
Is this a Regression?: Unknown

 Description   
Using the python SDK a customer has discovered that replacing a value on a locked document results in a key not found error. Mark Nunberg investigated from the SDK perspective and determined that the server is returning this incorrect error.


Example:
 python
Python 2.7.8 (default, Oct 19 2014, 16:02:00)
[GCC 4.2.1 Compatible Apple LLVM 6.0 (clang-600.0.54)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> from couchbase.bucket import Bucket
>>> b = Bucket('couchbase://localhost&#39;)
>>> b.upsert('x', 'value1')
OperationResult<RC=0x0, Key=u'x', CAS=0x44c778fbec280000>
>>> b.replace('x', 'value2')
OperationResult<RC=0x0, Key=u'x', CAS=0x2906244eee280000>
>>> b.lock('x', ttl=30)
ValueResult<RC=0x0, Key=u'x', Value=u'value2', CAS=0xb5784741f0280000, Flags=0x2000000>
>>> b.replace('x', 'value3')
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "couchbase/bucket.py", line 401, in replace
    persist_to=persist_to, replicate_to=replicate_to)
couchbase.exceptions._NotFoundError_0xD (generated, catch NotFoundError): <Key=u'x', RC=0xD[The key does not exist on the server], Operational Error, Results=1, C Source=(src/multiresult.c,282)>
>>> b.upsert('x', 'value3')
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "couchbase/bucket.py", line 361, in upsert
    persist_to, replicate_to)
couchbase.exceptions._KeyExistsError_0xC (generated, catch KeyExistsError): <Key=u'x', RC=0xC[The key already exists in the server. If you have supplied a CAS then the key exists with a CAS value different than specified], Operational Error, Results=1, C Source=(src/multiresult.c,282)>
>>>


 Comments   
Comment by Trond Norbye [ 24/Nov/14 ]
The return code is set in:

http://src.couchbase.org/source/xref/sherlock/ep-engine/src/ep.cc#843
Comment by Trond Norbye [ 24/Nov/14 ]
http://review.couchbase.org/#/c/43572/
http://review.couchbase.org/#/c/43573/
Comment by Matt Ingenthron [ 24/Nov/14 ]
Anil: Trond flagged me about this and I think you should review it-- also mentioned it via mail. At the least, it needs to be clearly release noted.

Comment by Anil Kumar [ 25/Nov/14 ]
Trond - Can we merge the changes (in-review) by today? We will be cutting RC1 build tomorrow.
Comment by Trond Norbye [ 26/Nov/14 ]
@Anil: merged. I assume _YOU_ make sure that it is properly stated in the release notes :-)




[MB-12750] XDCR ns_server Integration -- ns_server side Created: 21/Nov/14  Updated: 21/Nov/14

Status: Open
Project: Couchbase Server
Component/s: ns_server
Affects Version/s: feature-backlog
Fix Version/s: None
Security Level: Public

Type: Task Priority: Major
Reporter: Yu Sui Assignee: Yu Sui
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 32h
Time Spent: Not Specified
Original Estimate: 32h

Epic Link: XDCR next release

 Description   
New XDCR needs to be integrated with ns_server. This work item tracks the work that needs to do done on the ns_server side. Design doc is at follows:
https://drive.google.com/open?id=1ZbAtUWOZgBW1MXBDwQVHkuJDdKIotgFNjS7H6kZ_Nrs&authuser=0

The design doc for the work on the XDCR side is at follows:
https://drive.google.com/open?id=1TCmoBQQWiwn8qIvo2NDm-ySJfmo5JT9Zp7kvAghQz3c&authuser=0

Follows are the work items on the XDCR side:
https://www.couchbase.com/issues/browse/MB-12586
https://www.couchbase.com/issues/browse/MB-12720
https://www.couchbase.com/issues/browse/MB-12022




[MB-12748] Add support to get rev id information via sdk Created: 21/Nov/14  Updated: 21/Nov/14

Status: Open
Project: Couchbase Server
Component/s: clients
Affects Version/s: 3.0.1, 3.0, 3.0.2
Fix Version/s: sherlock
Security Level: Public

Type: Improvement Priority: Major
Reporter: Parag Agarwal Assignee: Matt Ingenthron
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   
This is currently not supported

Add support to get rev id information via sdk

This is of great use to the test team since we will be integrating python sdk to testrunner. I am sure support can use it for debugging issues. Example: revid was getting reset to 1 with Beats issue.




[MB-12747] Support multi_get and multi_set APIs in ForestDB Created: 21/Nov/14  Updated: 21/Nov/14

Status: Open
Project: Couchbase Server
Component/s: forestdb
Affects Version/s: feature-backlog
Fix Version/s: feature-backlog
Security Level: Public

Type: Bug Priority: Critical
Reporter: Chiyoung Seo Assignee: Chiyoung Seo
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
multi_get and multi_set APIs would be quite useful if an application wants to perform the I/O operation in a batched manner. To make multi_get and multi_set APIs more efficient, we will consider using asynchronous I/O library (e.g., libaio) to provide a better performance and disk utilization on SSDs or flash memory on mobile.




[MB-12746] Optimize fdb_iterator_seek API to avoid scanning a doc at a time Created: 21/Nov/14  Updated: 24/Nov/14

Status: Open
Project: Couchbase Server
Component/s: forestdb
Affects Version/s: techdebt-backlog
Fix Version/s: techdebt-backlog
Security Level: Public

Type: Bug Priority: Critical
Reporter: Chiyoung Seo Assignee: Jung-Sang Ahn
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
fdb_iterator_seek API currently scans a single doc at a time to seek a given key. This will cause significant overhead in case of a large iteration range. To avoid this, we need to improve the seek API, so that it can leverage the main index's search routines.

 Comments   
Comment by Chiyoung Seo [ 24/Nov/14 ]
Jung-Sang,

Once Sundar fixes the iteration bugs (http://review.couchbase.org/#/c/42859/) , can you work on optimizing the seek API? I would like to add this optimization to 1.0GA.
Comment by Jung-Sang Ahn [ 24/Nov/14 ]
Sure. I will work on this as soon as Sundar completes the iteration patch.




[MB-12745] memcached segfaults with jemalloc on a typical gnu/linux distribution Created: 21/Nov/14  Updated: 27/Nov/14  Resolved: 27/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: memcached
Affects Version/s: sherlock
Fix Version/s: sherlock
Security Level: Public

Type: Bug Priority: Major
Reporter: Aliaksey Artamonau Assignee: Dave Rigby
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
Checked on my ArchLinux and on Debian GNU/Linux.

System jemalloc library doesn't define je_ prefixed symbols:

# objdump -T /usr/lib64/libjemalloc.so.1 | grep je_
<empty output>

Instead it uses defines like this:

# define je_malloc malloc

So malloc ends up calling itself in a loop:

(gdb) bt
#0 0x000000000040965d in malloc (size=<error reading variable: Cannot access memory at address 0x7fff9fb41ff8>)
    at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:77
#1 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#2 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#3 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#4 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#5 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#6 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#7 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#8 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#9 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#10 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#11 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#12 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#13 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78
#14 0x000000000040966d in malloc (size=176) at /home/aa/dev/membase/repo30/memcached/daemon/alloc_hooks.c:78


 Comments   
Comment by Dave Rigby [ 21/Nov/14 ]
So I deliberately made our use of jemalloc use prefixed symbols. I can't really think of a straightforward way to suport both at runtime - the expectation is that we will use our own build of jemalloc and not a system one - particularly as we currently require a change which isn't yet in a released version of jemalloc (https://github.com/jemalloc/jemalloc/commit/e3a16fce5eb0c62a49e751f156d040c9f77fbc23).

The simplest fix for this is to use our build of jemalloc from cbdeps (http://hub.internal.couchbase.com/confluence/display/CR/Third-party+Dependencies). It isn't yet enabled by default (I need to speak to Ceej about it), but you can enable it by adding EXTRA_CMAKE_OPTIONS=-DCB_DOWNLOAD_DEPS=1 to your make arguments.

Alternatively you can revert to using TCMalloc by passing EXTRA_CMAKE_OPTIONS=-DCOUCHBASE_MEMORY_ALLOCATOR=tcmalloc.
Comment by Dave Rigby [ 21/Nov/14 ]
Thinking about this a little more, I can probably make us fail to compile if a non-prefixed jemalloc is used, which is probably preferable to a non-working build. I'll add something next week.
Comment by Dave Rigby [ 24/Nov/14 ]
Couple of fixes:

1) http://review.couchbase.org/#/c/43558/ [memcached] MB-12745: Disable jemalloc symbol renaming
2) http://review.couchbase.org/#/c/43559/ [tlm] Check for usable jemalloc library

Between these we will only enable jemalloc if the found libjemalloc.so has the correct je_ symbol prefix. For additional paranoia memcached will disable the symbol renaming which caused the je_malloc -> malloc transformation which triggered the stack overflow.




[MB-12744] n1ql stats: when run insert requests 'updates.Count' is increased, 'inserts.Count' stay 0 Created: 21/Nov/14  Updated: 26/Nov/14  Resolved: 26/Nov/14

Status: Resolved
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-alpha
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Colm Mchugh
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: 2h
Time Spent: Not Specified
Original Estimate: 2h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
and also updates are counted as 'inserts.Count'
insert query is:
cbq> insert into b0 key 'k2' values 1;
{
    "request_id": "cb26a9dd-8e57-49aa-9635-8ff3b7f988e4",
    "signature": null,
    "results": [
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "2.778ms",
        "executionTime": "2.301ms",
        "resultCount": 0,
        "resultSize": 0
    }
}

stats are:
{
"updates.Count": 2,
"inserts.Count": 0,
"requests.Count": 6,
"memstats": {"Alloc":10661184,"TotalAlloc":133655136,"Sys":302942264,"Lookups":51062,"Mallocs":1901836,"Frees":1882520,"HeapAlloc":10661184,"HeapSys":27918336,"HeapIdle":15605760,"HeapInuse":12312576,"HeapReleased":9347072,"HeapObjects":19316,"StackInuse":1236992,"StackSys":1441792,"MSpanInuse":101712,"MSpanSys":524288,"MCacheInuse":2024,"MCacheSys":131072,"BuckHashSys":1439992,"NextGC":19441520,"LastGC":1416595708190486000,"PauseTotalNs":298433000,"PauseNs":[413000,3844000,7253000,6790000,4462000,6711000,6772000,5758000,4866000,6773000,6657000,7297000,7175000,7085000,7267000,7269000,7158000,7225000,7336000,7242000,10748000,15459000,19209000,18442000,19851000,20166000,13960000,5744000,7038000,5456000,9660000,7844000,10689000,8814000,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"NumGC":34,"EnableGC":true,"DebugGC":false,"BySize":[{"Size":0,"Mallocs":0,"Frees":0},{"Size":8,"Mallocs":598628,"Frees":597434},{"Size":16,"Mallocs":397896,"Frees":396805},{"Size":32,"Mallocs":477517,"Frees":464386},{"Size":48,"Mallocs":19317,"Frees":18439},{"Size":64,"Mallocs":44319,"Frees":43603},{"Size":80,"Mallocs":4490,"Frees":4172},{"Size":96,"Mallocs":78852,"Frees":78660},{"Size":112,"Mallocs":19284,"Frees":19114},{"Size":128,"Mallocs":11706,"Frees":11629},{"Size":144,"Mallocs":4621,"Frees":4578},{"Size":160,"Mallocs":381,"Frees":208},{"Size":176,"Mallocs":96430,"Frees":96368},{"Size":192,"Mallocs":62814,"Frees":62553},{"Size":208,"Mallocs":10297,"Frees":10214},{"Size":224,"Mallocs":256,"Frees":232},{"Size":240,"Mallocs":9,"Frees":7},{"Size":256,"Mallocs":20738,"Frees":20402},{"Size":288,"Mallocs":28881,"Frees":28818},{"Size":320,"Mallocs":896,"Frees":887},{"Size":352,"Mallocs":423,"Frees":392},{"Size":384,"Mallocs":2923,"Frees":2901},{"Size":448,"Mallocs":8765,"Frees":8725},{"Size":512,"Mallocs":4471,"Frees":4431},{"Size":576,"Mallocs":4161,"Frees":4151},{"Size":640,"Mallocs":15,"Frees":14},{"Size":704,"Mallocs":378,"Frees":341},{"Size":768,"Mallocs":5,"Frees":5},{"Size":832,"Mallocs":12,"Frees":10},{"Size":1024,"Mallocs":408,"Frees":362},{"Size":1152,"Mallocs":26,"Frees":17},{"Size":1280,"Mallocs":3,"Frees":2},{"Size":1408,"Mallocs":182,"Frees":178},{"Size":1536,"Mallocs":343,"Frees":341},{"Size":1664,"Mallocs":17,"Frees":11},{"Size":2048,"Mallocs":144,"Frees":72},{"Size":2304,"Mallocs":167,"Frees":161},{"Size":2560,"Mallocs":7,"Frees":6},{"Size":3072,"Mallocs":0,"Frees":0},{"Size":3328,"Mallocs":7,"Frees":4},{"Size":4096,"Mallocs":737,"Frees":678},{"Size":4352,"Mallocs":5,"Frees":3},{"Size":4608,"Mallocs":2,"Frees":2},{"Size":5120,"Mallocs":155,"Frees":153},{"Size":6144,"Mallocs":38,"Frees":38},{"Size":6656,"Mallocs":17,"Frees":15},{"Size":6912,"Mallocs":0,"Frees":0},{"Size":8192,"Mallocs":274,"Frees":272},{"Size":8704,"Mallocs":2,"Frees":1},{"Size":10240,"Mallocs":5,"Frees":0},{"Size":10496,"Mallocs":0,"Frees":0},{"Size":12288,"Mallocs":157,"Frees":157},{"Size":14080,"Mallocs":4,"Frees":4},{"Size":16384,"Mallocs":93,"Frees":92},{"Size":17664,"Mallocs":249,"Frees":194},{"Size":20480,"Mallocs":4,"Frees":4},{"Size":21248,"Mallocs":0,"Frees":0},{"Size":24576,"Mallocs":15,"Frees":13},{"Size":24832,"Mallocs":0,"Frees":0},{"Size":28672,"Mallocs":165,"Frees":153},{"Size":32768,"Mallocs":62,"Frees":55}]},
"selects.Count": 4,
"active_requests.Count": 0,
"service_time.Count": 1229260000,
"result_count.Count": 4063,
"warnings.Count": 0,
"deletes.Count": 0,
"queued_requests.Count": 0,
"mutations.Count": 0,
"time": "2014-11-21T22:49:11.156126+04:00",
"cmdline": ["./cbq-engine","-datastore=http://172.27.33.17:8091"],
"request_time.Count": 1232249000,
"errors.Count": 1,
"result_size.Count": 1736823
}

 Comments   
Comment by Colm Mchugh [ 26/Nov/14 ]
commit 7024a9b3eaa666189aa655f98157b104d0be54bf




[MB-12743] unable to start cbq-engine with timeout option Created: 21/Nov/14  Updated: 23/Nov/14  Resolved: 21/Nov/14

Status: Closed
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
[root@kiwi-r116 cbq-engine]# ./cbq-engine -datastore=http://172.27.33.17:8091 -timeout=1
invalid value "1" for flag -timeout: time: missing unit in duration 1
Usage of ./cbq-engine:
  -acctstore="gometrics:": Accounting store address (http://URL or stub:)
  -certfile="": HTTPS certificate file
  -configstore="stub:": Configuration store address (http://URL or stub:)
  -datastore="": Datastore address (http://URL or dir:PATH or mock:)
  -debug=false: Debug mode
  -http=":8093": HTTP service address
  -https=":18093": HTTPS service address
  -keyfile="": HTTPS private key file
  -logger="": Logger implementation
  -metrics=true: Whether to provide metrics
  -mutation-limit=0: Maximum LIMIT for data modification statements; use zero or negative value to disable
  -namespace="default": Default namespace
  -order-limit=0: Maximum LIMIT for ORDER BY clauses; use zero or negative value to disable
  -readonly=false: Read-only mode
  -request-cap=262144: Maximum number of queued requests
  -signature=true: Whether to provide signature
  -threads=256: Thread count
  -timeout=0: Server execution timeout; use zero or negative value to disable
[root@kiwi-r116 cbq-engine]#


 Comments   
Comment by Gerald Sangudi [ 21/Nov/14 ]
Added examples to -timeout usage message.

Use -timeout=3s or -timeout=650ms etc.




[MB-12742] queries with both ORDER BY and LIMIT are always empty Created: 21/Nov/14  Updated: 22/Nov/14  Resolved: 21/Nov/14

Status: Closed
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-DP4
Fix Version/s: cbq-DP4
Security Level: Public

Type: Bug Priority: Major
Reporter: Iryna Mironava Assignee: Gerald Sangudi
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: 4h
Time Spent: Not Specified
Original Estimate: 4h

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
'name' attribute is in all items
query without order by shows some result
cbq> select name from default limit 3;
{
    "request_id": "0e68ff8f-14a9-494e-bd12-60ce9bd9ad27",
    "signature": {
        "name": "json"
    },
    "results": [
        {
            "name": "employee-13"
        },
        {
            "name": "employee-22"
        },
        {
            "name": "employee-10"
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "318.763ms",
        "executionTime": "318.633ms",
        "resultCount": 3,
        "resultSize": 135
    }
}

cbq>


but when i add order by :
cbq> select name from default order by name limit 3;
{
    "request_id": "82d27f15-953e-4e4b-814b-e042178ac26d",
    "signature": {
        "name": "json"
    },
    "results": [
        {},
        {},
        {}
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "838.88ms",
        "executionTime": "748.823ms",
        "resultCount": 3,
        "resultSize": 6
    }
}

cbq>


query with only order by works fine
 select name from default order by name;
"request_id": "e8e12cae-00a8-401e-8a24-6acbf2d75bcc",
    "signature": {
        "name": "json"
    },
    "results": [

<some_results>

 {
            "name": "employee-9"
        },
        {
            "name": "employee-9"
        },
        {
            "name": "employee-9"
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "1.087013s",
        "executionTime": "1.086893s",
        "resultCount": 4061,
        "resultSize": 180202
    }
}



 Comments   
Comment by Gerald Sangudi [ 21/Nov/14 ]
Please post:

explain select name from default order by name limit 3;

Thanks.
Comment by Iryna Mironava [ 21/Nov/14 ]
cbq> explain select name from default order by name limit 3;
{
    "request_id": "33e86bd7-7651-4b7b-9928-8d5520353dcb",
    "signature": "json",
    "results": [
        {
            "#operator": "Sequence",
            "~children": [
                {
                    "#operator": "Sequence",
                    "~children": [
                        {
                            "#operator": "PrimaryScan",
                            "index": "#primary"
                        },
                        {
                            "#operator": "Parallel",
                            "~child": {
                                "#operator": "Sequence",
                                "~children": [
                                    {
                                        "#operator": "Fetch",
                                        "keyspace": "default",
                                        "namespace": "default"
                                    },
                                    {
                                        "#operator": "InitialProject",
                                        "result_terms": [
                                            {
                                                "expr": "(`default`.`name`)"
                                            }
                                        ]
                                    }
                                ]
                            }
                        }
                    ]
                },
                {
                    "#operator": "Order",
                    "sort_terms": [
                        {
                            "expr": "(`default`.`name`)"
                        }
                    ]
                },
                {
                    "Expr": "3",
                    "Type": "limit"
                },
                {
                    "#operator": "Parallel",
                    "~child": {
                        "#operator": "FinalProject"
                    }
                }
            ]
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "3.336ms",
        "executionTime": "3.179ms",
        "resultCount": 1,
        "resultSize": 1918
    }
}

cbq>
Comment by Gerald Sangudi [ 21/Nov/14 ]
The problem is that MISSING sorts as the smallest value. So document with name=MISSING will show first, and appear as empty objects.

Try ORDER BY name desc




[MB-12741] Docs NRU boolean incorrect Created: 21/Nov/14  Updated: 24/Nov/14  Resolved: 24/Nov/14

Status: Closed
Project: Couchbase Server
Component/s: documentation
Affects Version/s: 3.0
Fix Version/s: None
Security Level: Public

Type: Bug Priority: Major
Reporter: Ian McCloy Assignee: Ruth Harris
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Triage: Untriaged
Is this a Regression?: Unknown

 Description   
http://docs.couchbase.com/admin/admin/CLI/CBepctl/cbepctl-thresholds.html

"The server determines that items are not frequently used based on a not-recently-used (NRU) boolean. "

Boolean would imply that NRU is either true or false.
This is incorrect, NRU is a score, it can be 0,1,2 etc.. it's not a boolean value.

 Comments   
Comment by Ruth Harris [ 24/Nov/14 ]
Fixed in 3.0. Re: "a not-recently-used (NRU) boolean. ". Changed boolean to value.

Note: Publishing to the Couchbase website occur within 24 hours.

`Ruth




[MB-12740] Improve autofailover for replica counts over 1 Created: 21/Nov/14  Updated: 21/Nov/14

Status: Open
Project: Couchbase Server
Component/s: ns_server
Affects Version/s: 2.5.1, 3.0
Fix Version/s: None
Security Level: Public

Type: Improvement Priority: Major
Reporter: Perry Krug Assignee: Aleksey Kondratenko
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   
If all buckets in a cluster have more than 1 replica, we should be able to automatically sustain the loss of more than one node. I agree we still don't want to do anything if multiple nodes fail at one time, but if one node fails and is automatically failed over, a second node failure (or third) should also be automatically failed over if there are enough replicas.

We likely also want to add a setting for the cluster to limit the max number of nodes (extending the concept of autofailover quota we currently have).




[MB-12739] Improve Auto-failover for RZA Created: 21/Nov/14  Updated: 21/Nov/14

Status: Open
Project: Couchbase Server
Component/s: ns_server
Affects Version/s: 2.5.1, 3.0
Fix Version/s: None
Security Level: Public

Type: Improvement Priority: Major
Reporter: Perry Krug Assignee: Aleksey Kondratenko
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   
If an entire zone fails, Couchbase should be able to automatically failover the entire group.

This should have similar split-brain precautions as our individual node autofailover in the sense that we only support autofailover of an entire group if there are 3 or more groups configured and so long as only one group appears down at a time.

 Comments   
Comment by Perry Krug [ 21/Nov/14 ]
The improvement of mb-12740 should also extend to multiple zones failing in succession when >1 replicas are configured




[MB-12738] Checkpoints are always purged if there are no cursors in them Created: 20/Nov/14  Updated: 25/Nov/14

Status: Open
Project: Couchbase Server
Component/s: couchbase-bucket
Affects Version/s: sherlock
Fix Version/s: sherlock
Security Level: Public

Type: Task Priority: Major
Reporter: Mike Wiederhold Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   
We are aggressively removing checkpoints from memory. In this case I loaded 100k items into Couchbase, waited, and observed that there was only one item in each checkpoint manager. We should keep checkpoints in memory if we have space.

Mikes-MacBook-Pro:ep-engine mikewied$ management/cbstats 10.5.2.34:12000 checkpoint | grep num_checkpoint_items | cut -c 44- | awk '{s+=$1} END {print s}'
1024




[MB-12736] TRACE log level should log EXPLAIN for every request Created: 20/Nov/14  Updated: 20/Nov/14  Due: 08/Dec/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-alpha
Fix Version/s: cbq-alpha
Security Level: Public

Type: Improvement Priority: Major
Reporter: Gerald Sangudi Assignee: Colm Mchugh
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 4h
Time Spent: Not Specified
Original Estimate: 4h


 Description   
Useful for the support team.




[MB-12734] To be able to change the Administrator user password in the UI Created: 20/Nov/14  Updated: 20/Nov/14

Status: Open
Project: Couchbase Server
Component/s: UI
Affects Version/s: 3.0.1
Fix Version/s: None
Security Level: Public

Type: Improvement Priority: Major
Reporter: Patrick Varley Assignee: Aleksey Kondratenko
Resolution: Unresolved Votes: 0
Labels: customer
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   
It would be good if the Administrator password could be changed in the UI.




[MB-12733] Design and implement go_cbq library Created: 20/Nov/14  Updated: 20/Nov/14  Due: 08/Dec/14

Status: Open
Project: Couchbase Server
Component/s: query
Affects Version/s: cbq-alpha
Fix Version/s: cbq-alpha
Security Level: Public

Type: Epic Priority: Critical
Reporter: Gerald Sangudi Assignee: Manik Taneja
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: 40h
Time Spent: Not Specified
Original Estimate: 40h

Epic Name: go_cbq
Epic Status: To Do

 Description   
Client/go_cbq

This package provides a client library that will be used by the command-line shell to encapsulate cluster-awareness and other connectivity concerns.

The library will implement the standard golang database APIs at database/sql and database/sql/driver.

The library will connect using the Query REST API and the Query Clustering API.




Generated at Thu Nov 27 08:51:55 CST 2014 using JIRA 5.2.4#845-sha1:c9f4cc41abe72fb236945343a1f485c2c844dac9.