Write_lock error has occurred after inserting 12M data

David Smith dizzyd at basho.com
Fri Jul 30 21:34:33 EDT 2010


That's only a partial paste, correct? How many partitions
({ring_creation_size, 64} in your etc/app.config) do you have defined? There
should be a write lock file open for each partition. Also, what is your
ulimit -n set to?

Thanks,

D.

On Fri, Jul 30, 2010 at 5:09 PM, Alex Wolfe <alex at activeprospect.com> wrote:

> $ lsof -p 16129 | awk '{print $9}'| uniq -c | grep lock
>   1
> /usr/local/Cellar/riak/0.12.0/libexec/data/bitcask/913438523331814323877303020447676887284957839360/bitcask.write.lock
>   1
> /usr/local/Cellar/riak/0.12.0/libexec/data/bitcask/959110449498405040071168171470060731649205731328/bitcask.write.lock
>   1
> /usr/local/Cellar/riak/0.12.0/libexec/data/bitcask/936274486415109681974235595958868809467081785344/bitcask.write.lock
>   1
> /usr/local/Cellar/riak/0.12.0/libexec/data/bitcask/411047335499316445744786359201454599278231027712/bitcask.write.lock
>   1
> /usr/local/Cellar/riak/0.12.0/libexec/data/bitcask/456719261665907161938651510223838443642478919680/bitcask.write.lock
>   1
> /usr/local/Cellar/riak/0.12.0/libexec/data/bitcask/433883298582611803841718934712646521460354973696/bitcask.write.lock
>   1
> /usr/local/Cellar/riak/0.12.0/libexec/data/bitcask/388211372416021087647853783690262677096107081728/bitcask.write.lock
>
>
> On Jul 30, 2010, at 6:03 PM, David Smith wrote:
>
> > Yup, that looks like the file handle leak. You can verify by using
> > lsof on the server and looking for multiple handles to
> > bitcask.write.lock. Something like:
> >
> > lsof -p pid | awk '{print $9}'| uniq -c
> >
> > D.
> >
> > On Friday, July 30, 2010, Alex Wolfe <alex at activeprospect.com> wrote:
> >> Hey David.
> >> Does the below log output look like it could be caused by the issue you
> fixed?
> >> Alex
> >>
> >> ==== Fri Jul 30 14:22:34 CDT 2010
> >> =ERROR REPORT==== 30-Jul-2010::14:22:34 ===** State machine <0.176.0>
> terminating ** Last event in was {riak_vnode_req_v1,
> 593735040165679310520246963290989976735222595584,
> {fsm,undefined,<0.12466.0>},                     {riak_kv_put_req_v1,
>                {<<"test.groups">>,<<"EghzXywWrGGtp2fCcSLoatIdjML">>},
>                {r_object,<<"test.groups">>,
> <<"EghzXywWrGGtp2fCcSLoatIdjML">>,                       [{r_content,
>                   {dict,5,16,16,8,80,48,
>  {[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
>  {{[],[],                            [[<<"Links">>]],
>      [],[],[],[],[],[],[],
>  [[<<"content-type">>,97,112,112,108,105,99,97,
>  116,105,111,110,47,106,115,111,110],
> [<<"X-Riak-VTag">>,89,69,78,55,55,111,66,121,73,
>  69,78,53,122,101,85,105,117,68,89,80,52]],
>  [],[],                            [[<<"X-Riak-Last-Modified">>|
>                  {1280,517754,951062}]],                            [],
>                        [[<<"X-Riak-Meta">>]]}}},
> <<"{\"name\":\"foo\",\"created_at\":\"2010-07-30T19:22:34.947Z\",\"type\":\"group\",\"version\":1}">>}],
>                       [{<<0,55,119,231>>,{1,63447736954}}],
>       {dict,1,16,16,8,80,48,
>  {[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
>  {{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
>  [[clean|true]],                          []}}},
> undefined},                      33218311,63447736954,
>  [{returnbody,true}]}}** When State == active**      Data  ==
> {state,593735040165679310520246963290989976735222595584,
>   riak_kv_vnode,
> {state,593735040165679310520246963290989976735222595584,
>           riak_kv_bitcask_backend,
>  {#Ref<0.0.0.611>,
> "data/bitcask/593735040165679310520246963290989976735222595584"},
>                    [],false},                       undefined,none}** Reason
> for termination = ** {{badmatch,{error,emfile}},
> [{bitcask_fileops,create_file_loop,3},    {bitcask,put,3},
>  {riak_kv_bitcask_backend,put,3},    {riak_kv_vnode,perform_put,3},
>  {riak_kv_vnode,do_put,7},    {riak_kv_vnode,handle_command,3},
>  {riak_core_vnode,vnode_command,3},    {gen_fsm,handle_msg,7}]}
> >> =ERROR REPORT==== 30-Jul-2010::14:22:35 ===Failed to open lock file
> data/bitcask/593735040165679310520246963290989976735222595584/bitcask.write.lock:
> emfile
> >> =ERROR REPORT==== 30-Jul-2010::14:22:35 ===** State machine <0.12471.0>
> terminating ** Last event in was {riak_vnode_req_v1,
> 593735040165679310520246963290989976735222595584,
> {fsm,undefined,<0.12470.0>},                     {riak_kv_put_req_v1,
>                {<<"test.users">>,<<"ZrAxzFghd51VG902GuCcJ2gYOMJ">>},
>              {r_object,<<"test.users">>,
> <<"ZrAxzFghd51VG902GuCcJ2gYOMJ">>,                       [{r_content,
>                   {dict,5,16,16,8,80,48,
>  {[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
>  {{[],[],                            [[<<"Links">>,
>      {{<<"test.groups">>,
>  <<"EghzXywWrGGtp2fCcSLoatIdjML">>},
> <<"groups">>}]],                            [],[],[],[],[],[],[],
>                  [[<<"content-type">>,97,112,112,108,105,99,97,
>                  116,105,111,110,47,106,115,111,110],
>       [<<"X-Riak-VTag">>,50,88,97,105,85,49,70,49,55,
>        54,48,71,113,115,75,103,54,102,84,56,118,84]],
>      [],[],
>  [[<<"X-Riak-Last-Modified">>|{1280,517755,638}]],
>  [],                            [[<<"X-Riak-Meta">>]]}}},
>
> <<"{\"name\":\"bar\",\"created_at\":\"2010-07-30T19:22:34.998Z\",\"type\":\"user\",\"version\":1}">>}],
>                       [{<<3,30,180,15>>,{1,63447736955}}],
>     {dict,1,16,16,8,80,48,
>  {[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
>  {{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
>  [[clean|true]],                          []}}},
> undefined},                      122945524,63447736955,
>  [{returnbody,true}]}}** When State == active**      Data  ==
> {state,593735040165679310520246963290989976735222595584,
>   riak_kv_vnode,
> {state,593735040165679310520246963290989976735222595584,
>           riak_kv_bitcask_backend,
>  {#Ref<0.0.0.16357>,
> "data/bitcask/593735040165679310520246963290989976735222595584"},
>                    [],false},                       undefined,none}** Reason
> for termination = ** {bad_return_value,{error,{write_locked,emfile}}}
> >> ==> sasl-error.log <==
> >> =CRASH REPORT==== 30-Jul-2010::14:22:35 === crasher:   initial call:
> riak_core_vnode:init/1   pid: <0.176.0>   registered_name: []   exception
> exit: {{badmatch,{error,emfile}},
>  [{bitcask_fileops,create_file_loop,3},                     {bitcask,put,3},
>                     {riak_kv_bitcask_backend,put,3},
> {riak_kv_vnode,perform_put,3},                     {riak_kv_vnode,do_put,7},
>                     {riak_kv_vnode,handle_command,3},
> {riak_core_vnode,vnode_command,3},
> {gen_fsm,handle_msg,7}]}     in function  gen_fsm:terminate/7   ancestors:
> [riak_core_vnode_sup,riak_core_sup,<0.98.0>]   messages: []   links:
> [#Port<0.3507>,<0.100.0>]   dictionary: []   trap_exit: true   status:
> running   heap_size: 1597   stack_size: 24   reductions: 11185 neighbours:
> >> =SUPERVISOR REPORT==== 30-Jul-2010::14:22:35 ===    Supervisor:
> {local,riak_core_vnode_sup}    Context:    child_terminated    Reason:
> {{badmatch,{error,emfile}},
> [{bitcask_fileops,create_file_loop,3},                  {bitcask,put,3},
>              {riak_kv_bitcask_backend,put,3},
>  {riak_kv_vnode,perform_put,3},                  {riak_kv_vnode,do_put,7},
>                {riak_kv_vnode,handle_command,3},
>  {riak_core_vnode,vnode_command,3},
>  {gen_fsm,handle_msg,7}]}    Offender:   [{pid,<0.176.0>},
> {name,undefined},                 {mfa,
> {riak_core_vnode,start_link,                         [riak_kv_vnode,
>                  593735040165679310520246963290989976735222595584]}},
>           {restart_type,temporary},                 {shutdown,brutal_kill},
>                 {child_type,worker}]
> >>
> >> =CRASH REPORT==== 30-Jul-2010::14:22:35 === crasher:   initial call:
> riak_core_vnode:init/1   pid: <0.12471.0>   registered_name: []   exception
> exit: {bad_return_value,{error,{write_locked,emfile}}}     in function
>  gen_fsm:terminate/7   ancestors:
> [riak_core_vnode_sup,riak_core_sup,<0.98.0>]   messages: []   links:
> [<0.100.0>]   dictionary: []   trap_exit: true   status: running
> heap_size: 2584   stack_size: 24   reductions: 1955 neighbours:
> >> =SUPERVISOR REPORT==== 30-Jul-2010::14:22:35 ===    Supervisor:
> {local,riak_core_vnode_sup}    Context:    child_terminated    Reason:
> {bad_return_value,{error,{write_locked,emfile}}}    Offender:
> [{pid,<0.12471.0>},                 {name,undefined},                 {mfa,
>                     {riak_core_vnode,start_link,
> [riak_kv_vnode,
>  593735040165679310520246963290989976735222595584]}},
> {restart_type,temporary},                 {shutdown,brutal_kill},
>       {child_type,worker}]
> >>
> >> ==> erlang.log.4 <==
> >> =ERROR REPORT==== 30-Jul-2010::14:23:27 ===** Generic server memsup
> terminating ** Last message in was {'EXIT',<0.21020.78>,
>      {emfile,                              [{erlang,open_port,
>                     [{spawn,"/bin/sh -s unix:cmd 2>&1"},
>                [stream]]},
> {os,start_port_srv_loop,2}]}}** When Server state == {state,{unix,darwin},
>                            false,
>  {1897500000,7776508000},                              {<0.81.0>,972008},
>                            false,60000,30000,0.8,0.05,<0.21020.78>,
>                      #Ref<0.0.2.58535>,undefined,
>    [reg],                              []}** Reason for termination == **
> {emfile,[{erlang,open_port,[{spawn,"/bin/sh -s unix:cmd 2>&1"},[stream]]},
>         {os,start_port_srv_loop,2}]}
> >> =ERROR REPORT==== 30-Jul-2010::14:23:27 ===** Generic server memsup
> terminating ** Last message in was {'EXIT',<0.21186.78>,
>      {emfile,                              [{erlang,open_port,
>                     [{spawn,"/bin/sh -s unix:cmd 2>&1"},
>                [stream]]},
> {os,start_port_srv_loop,2}]}}** When Server state == {state,{unix,darwin},
>                            false,undefined,undefined,false,60000,30000,
>                          0.8,0.05,<0.21186.78>,#Ref<0.0.2.58551>,
>                    undefined,                              [reg],
>                    []}** Reason for termination == **
> {emfile,[{erlang,open_port,[{spawn,"/bin/sh -s unix:cmd 2>&1"},[stream]]},
>         {os,start_port_srv_loop,2}]}
> >> =ERROR REPORT==== 30-Jul-2010::14:23:27 ===** Generic server memsup
> terminating ** Last message in was {'EXIT',<0.21252.78>,
>      {emfile,                              [{erlang,open_port,
>                     [{spawn,"/bin/sh -s unix:cmd 2>&1"},
>                [stream]]},
> {os,start_port_srv_loop,2}]}}** When Server state == {state,{unix,darwin},
>                            false,undefined,undefined,false,60000,30000,
>                          0.8,0.05,<0.21252.78>,#Ref<0.0.2.58559>,
>                    undefined,                              [reg],
>                    []}** Reason for termination == **
> {emfile,[{erlang,open_port,[{spawn,"/bin/sh -s unix:cmd 2>&1"},[stream]]},
>         {os,start_port_srv_loop,2}]}
> >> =ERROR REPORT==== 30-Jul-2010::14:23:27 ===** Generic server memsup
> terminating ** Last message in was {'EXIT',<0.21374.78>,
>      {emfile,                              [{erlang,open_port,
>                     [{spawn,"/bin/sh -s unix:cmd 2>&1"},
>                [stream]]},
> {os,start_port_srv_loop,2}]}}** When Server state == {state,{unix,darwin},
>                            false,undefined,undefined,false,60000,30000,
>                          0.8,0.05,<0.21374.78>,#Ref<0.0.2.58569>,
>                    undefined,                              [reg],
>                    []}** Reason for termination == **
> {emfile,[{erlang,open_port,[{spawn,"/bin/sh -s unix:cmd 2>&1"},[stream]]},
>         {os,start_port_srv_loop,2}]}
> >> =ERROR REPORT==== 30-Jul-2010::14:23:27 ===** Generic server memsup
> terminating ** Last message in was {'EXIT',<0.21396.78>,
>      {emfile,                              [{erlang,open_port,
>                     [{spawn,"/bin/sh -s unix:cmd 2>&1"},
>                [stream]]},
> {os,start_port_srv_loop,2}]}}** When Server state == {state,{unix,darwin},
>                            false,undefined,undefined,false,60000,30000,
>                          0.8,0.05,<0.21396.78>,#Ref<0.0.2.58575>,
>                    undefined,                              [reg],
>                    []}** Reason for termination == **
> {emfile,[{erlang,open_port,[{spawn,"/bin/sh -s unix:cmd 2>&1"},[stream]]},
>         {os,start_port_srv_loop,2}]}
> >> =ERROR REPORT==== 30-Jul-2010::14:23:27 ===** State machine <0.175.0>
> terminating ** Last event in was {riak_vnode_req_v1,
> 570899077082383952423314387779798054553098649600,
> {fsm,undefined,<0.12470.0>},                     {riak_kv_put_req_v1,
>                {<<"test.users">>,<<"ZrAxzFghd51VG902GuCcJ2gYOMJ">>},
>              {r_object,<<"test.users">>,
> <<"ZrAxzFghd51VG902GuCcJ2gYOMJ">>,                       [{r_content,
>                   {dict,5,16,16,8,80,48,
>  {[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
>  {{[],[],                            [[<<"Links">>,
>      {{<<"test.groups">>,
>  <<"EghzXywWrGGtp2fCcSLoatIdjML">>},
> <<"groups">>}]],                            [],[],[],[],[],[],[],
>                  [[<<"content-type">>,97,112,112,108,105,99,97,
>                  116,105,111,110,47,106,115,111,110],
>       [<<"X-Riak-VTag">>,50,88,97,105,85,49,70,49,55,
>        54,48,71,113,115,75,103,54,102,84,56,118,84]],
>      [],[],
>  [[<<"X-Riak-Last-Modified">>|{1280,517755,638}]],
>  [],                            [[<<"X-Riak-Meta">>]]}}},
>
> <<"{\"name\":\"bar\",\"created_at\":\"2010-07-30T19:22:34.998Z\",\"type\":\"user\",\"version\":1}">>}],
>                       [{<<3,30,180,15>>,{1,63447736955}}],
>     {dict,1,16,16,8,80,48,
>  {[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
>  {{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
>  [[clean|true]],                          []}}},
> undefined},                      122945524,63447736955,
>  [{returnbody,true}]}}** When State == active**      Data  ==
> {state,570899077082383952423314387779798054553098649600,
>   riak_kv_vnode,
> {state,570899077082383952423314387779798054553098649600,
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.basho.com/pipermail/riak-users_lists.basho.com/attachments/20100730/c1bdedec/attachment.html>


More information about the riak-users mailing list