Restoring to Search-indexed buckets results in a hook_crashed Riak error

[dmitrizagidulin]

To reproduce:
On a riak 1.3 devrel build, with backend riak_kv_eleveldb_backend, riak Search enabled, and the following default properties in app.config (these shouldn't matter, adding them for completeness):

{default_bucket_props, [
{n_val,1},
{r,1},
{w,1}]},

{anti_entropy, {on, []}}

Launch riak, enable indexing on a bucket, and insert a test object:

$ bin/riak start
$ bin/search-cmd install test_bucket
$ curl -X PUT -H "content-type:application/json" http://127.0.0.1:10018/buckets/test_bucket/keys/key1 -d @- << EOF
{"obj_key":"object_value"}
EOF

Double-check the bucket list:

$ curl http://127.0.0.1:10018/buckets?buckets=true
{"buckets":["_rsid_test_bucket","test_bucket"]}

Now back up the cluster via DataMigrator 0.2.5:

$ mkdir ~/data/Test
$ java -jar ~/riak/riak-data-migrator-0.2.5/riak-data-migrator-0.2.5.jar -d -a -r ~/data/Test -h 127.0.0.1 -p 10017 -H 10018
Destination PB Port not specified, using the default: 8087

Dumping bucket _rsid_test_bucket
100% completed. Read 1 @ 11 obj/sec          
Dumping bucket test_bucket
100% completed. Read 1 @ 50 obj/sec          
Dump Summary:
         Bucket     Objects     Seconds    Objs/Sec     Size/KB Val. Err.
_rsid_test_bucket           1         0.1        18.9           0         0
    test_bucket           1         0.0        50.0           0         0
       Total: 2           2         0.1        27.4           0         0

Stop riak and clear the data directory:

$ bin/riak stop
$ rm -rf data/*
$ bin/riak start
$ curl http://127.0.0.1:10018/buckets?buckets=true
{"buckets":[]}

Now, restoring the buckets via DataMigrator without re-enabling Search indexing on those buckets works just fine.
But, if you enable indexing and try to restore, it errors out:

$ bin/search-cmd install test_bucket
$ java -jar ~/riak/riak-data-migrator-0.2.5/riak-data-migrator-0.2.5.jar -l -a -r ~/data/Test -h 127.0.0.1 -p 10017 -H 10018
Destination PB Port not specified, using the default: 8087
Loading bucket _rsid_test_bucket
100% completed. Wrote 1 @ 8 obj/sec          
Loading bucket test_bucket
0% completed. Wrote 0 @ 0 obj/sec          
Load Summary:
         Bucket     Objects     Seconds    Objs/Sec     Size/KB Val. Err.
_rsid_test_bucket           1         0.1         8.8           0         0
    test_bucket       ERROR       ERROR       ERROR       ERROR     ERROR
       Total: 2           1         0.1         8.8           0         0

Data migrator error log contents:

09:05:45.285 [RiakObjectWriterThread-0] ERROR c.b.p.datamigrator.riak.ClientWriter - Max store retries 3 reached on key test_bucket / key1
09:05:45.292 [main] ERROR c.b.p.datamigrator.BucketLoader - Riak error storing value to test_bucket
com.basho.riak.pbc.RiakError: {precommit_fail,
    {hook_crashed,{riak_search_kv_hook,precommit,error,function_clause}}}
    at com.basho.riak.pbc.RiakConnection.receive(RiakConnection.java:125) ~[riak-client-1.1.0.jar:na]
    at com.basho.riak.pbc.RiakClient.store(RiakClient.java:581) ~[riak-client-1.1.0.jar:na]
    at com.basho.riak.client.raw.pbc.PBClientAdapter.store(PBClientAdapter.java:177) ~[riak-client-1.1.0.jar:na]
    at com.basho.riak.client.raw.pbc.PBClientAdapter.store(PBClientAdapter.java:197) ~[riak-client-1.1.0.jar:na]
    at com.basho.proserv.datamigrator.riak.ClientWriter.storeRiakObject(ClientWriter.java:37) ~[riak-data-migrator-0.2.5.jar:na]
    at com.basho.proserv.datamigrator.riak.ClientWriter.storeRiakObject(ClientWriter.java:48) ~[riak-data-migrator-0.2.5.jar:na]
    at com.basho.proserv.datamigrator.riak.ClientWriter.storeRiakObject(ClientWriter.java:48) ~[riak-data-migrator-0.2.5.jar:na]
    at com.basho.proserv.datamigrator.riak.ClientWriter.storeRiakObject(ClientWriter.java:48) ~[riak-data-migrator-0.2.5.jar:na]
    at com.basho.proserv.datamigrator.riak.ClientWriter.storeRiakObject(ClientWriter.java:28) ~[riak-data-migrator-0.2.5.jar:na]
    at com.basho.proserv.datamigrator.riak.ThreadedClientDataWriter$RiakObjectWriterThread.run(ThreadedClientDataWriter.java:187) ~[riak-data-migrator-0.2.5.jar:na]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439) ~[na:1.6.0_51]
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) ~[na:1.6.0_51]
    at java.util.concurrent.FutureTask.run(FutureTask.java:138) ~[na:1.6.0_51]
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895) ~[na:1.6.0_51]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918) ~[na:1.6.0_51]
    at java.lang.Thread.run(Thread.java:680) ~[na:1.6.0_51]

Riak error log contents

2013-09-16 09:15:17.252 [error] <0.1305.0> webmachine error: path="/buckets/test_bucket/keys/key1"
{error,{error,badarg,
[{erlang,iolist_to_binary,
 [{hook_crashed,{riak_search_kv_hook,precommit,error,function_clause}}],
 []},{wrq,append_to_response_body,2,[{file,"src/wrq.erl"},{line,205}]},{riak_kv_wm_object,handle_common_error,3,[{file,"src/riak_kv_wm_object.erl"},{line,998}]},{webmachine_resource,resource_call,3,
[{file,"src/webmachine_resource.erl"},{line,183}]},{webmachine_resource,do,3,[{file,"src/webmachine_resource.erl"},{line,141}]},{webmachine_decision_core,resource_call,1,[{file,"src/webmachine_decision_core.erl"},{line,48}]},{webmachine_decision_core,accept_helper,0,[{file,"src/webmachine_decision_core.erl"},{line,606}]},{webmachine_decision_core,decision,1,
[{file,"src/webmachine_decision_core.erl"},{line,577}]}]}}

At this point (after trying to restore search-indexed buckets via DataMigrator), a plain HTTP put to the same bucket results in the same error:

$ curl -X PUT -H "content-type:application/json" http://127.0.0.1:10018/buckets/test_bucket/keys/key1 -d @- << EOF
> {"obj_key":"object_value"}
> EOF
<html><head><title>500 Internal Server Error</title></head><body><h1>Internal Server Error</h1>The server encountered an error while processing this request:<br><pre>{error,
    {error,badarg,
        [{erlang,iolist_to_binary,
             [{hook_crashed,
                  {riak_search_kv_hook,precommit,error,function_clause}}],
             []},
         {wrq,append_to_response_body,2,[{file,"src/wrq.erl"},{line,205}]},
         {riak_kv_wm_object,handle_common_error,3,
             [{file,"src/riak_kv_wm_object.erl"},{line,998}]},
         {webmachine_resource,resource_call,3,
             [{file,"src/webmachine_resource.erl"},{line,183}]},
         {webmachine_resource,do,3,
             [{file,"src/webmachine_resource.erl"},{line,141}]},
         {webmachine_decision_core,resource_call,1,
             [{file,"src/webmachine_decision_core.erl"},{line,48}]},
         {webmachine_decision_core,accept_helper,0,
             [{file,"src/webmachine_decision_core.erl"},{line,606}]},
         {webmachine_decision_core,decision,1,
             [{file,"src/webmachine_decision_core.erl"},{line,577}]}]}}</pre><P><HR><ADDRESS>mochiweb+webmachine web server</ADDRESS></body></html>

So, something is getting borked during the restoration process.

[dmitrizagidulin]

Ok, the error above results from backing up the _rsid_* buckets (such as the _rsid_test_bucket that automatically gets created in the repro steps above).
These are internal-use only buckets created by Riak Search, and contain the documents that search actually indexed.
The to-do issue for filtering them out is here: #4

As for this bug, for current versions of the DataMigrator, it can be avoided by manually deleting _rsid_* directories in the exported data dirs. I'll add that to the README notes.
Closing.