Unexpected mvel update NullPointerException

[ctrochalakis]

Hello,

We hit an interesting bug a few days ago with our testing cluster. It appears that if we do 2 consecutive updates to a document, right after an elasticsearch restart, the second update fails with NullPointerException. If we run the test script a second time (without restarting the server), the update succeeds.

Our test script that demostrates the issue:

# sudo /etc/init.d/elasticsearch restart && sleep 10 && bash test_es_mvel_issue

echo "Delete everything"
curl -X DELETE 'http://localhost:9200/_all?pretty'

echo "Create test index"
curl -X PUT 'http://localhost:9200/test?pretty'

echo "Add a document"
curl -X PUT 'http://localhost:9200/test/tweet/1?pretty' -d '{
  "smth": "m"
}'

echo "Issue an update using mvel"
curl -X POST 'http://localhost:9200/test/tweet/1/_update?pretty' -d '{
  "script": "foreach(field : updates.entrySet()) { ctx._source[field.key] = field.value; }",
  "params": {
    "updates": {
      "1": 1,
      "2": 1,
      "3": 1,
      "availability": null,
      "5": 1,
      "a": 1,
      "b": 1,
      "c": 1,
      "d": 1,
      "e": 1,
      "f": 1,
      "g": 1,
      "h": 1,
      "i": 1,
      "j": 1,
      "k": 1,
      "l": 1,
      "m": 1,
      "n": 1,
      "o": 1,
      "p": 1,
      "q": 1,
      "r": 1,
      "s": 1,
      "t": 1,
      "flter": 1
    }
  }
}'

echo "Issue a second update"
curl -X POST 'http://localhost:9200/test/tweet/1/_update?pretty' -d '{
  "script": "foreach(field : updates.entrySet()) { ctx._source[field.key] = field.value; }",
  "params": {
    "updates": {
      "1": 1,
      "2": 1,
      "3": 1,
      "availability": null,
      "5": 1,
      "a": 1,
      "b": 1,
      "c": 1,
      "d": 1,
      "e": 1,
      "f": 1,
      "g": 1,
      "h": 1,
      "i": 1,
      "j": 1,
      "k": 1,
      "l": 1,
      "m": 1,
      "n": 1,
      "o": 1,
      "p": 1,
      "q": 1,
      "r": 1,
      "s": 1,
      "t": 1,
      "flter": 1
    }
  }
}'

#2014-03-20T15:20:30+02:00 [400] (0.016s)
#
# {
#   "error": "ElasticSearchIllegalArgumentException[failed to execute script]; nested: NullPointerException; ",
#   "status": 400
# 
# }

The bug is reproducible to all elasticsearch versions (0.90, 1.0, 1.1, master).

Some interesting points that we noticed:

• It seems to depend on the payload, if we remove an attribute from the updates hash everything works.
• If we add some whitespace to the second's update mvel script, the update succeeds. Probably because it skips a cache.

[hhoffstaette]

The good news: I can reproduce this successfully - thanks for the detailed instructions.

The less good news is that it looks like a bug in MVEL's embedded ASM version:
http://jira.codehaus.org/browse/MVEL-308

The bug manifests itself in that creating the document with availability=null works, but MVEL's ASM optimizer stumbles over the second update since it again contains availability=null.
I'm not sure why this happens only once, but it does so repeatably after a restart.
Updating an initially created document with a non-null value works fine.

[ctrochalakis]

Great, I am glad that you have pinpointed the problem. Probably a typo in The MVEL source.

But, yes, it's very strange that it happens only after a restart.. And also, why does removing an non-null value from both updates fixes everything?

[hhoffstaette]

That is indeed weird, and I have no idea why it does not trip over the same bug. Nevertheless MVEL must be fixed first, then we can see where this goes.

[hhoffstaette]

Fixed upstream in mvel/mvel@f61874a

[spinscale]

@ctrochalakis is it possible to test with master/1.x branch and report if it works for you?

[kevinkluge]

Note that @kimchy upgraded ES to MVEL 2.2.0, which was released after the f61... commit referenced by Holger. However, Holger's referenced bug remains open. I'm not sure what state the MVEL fix is in.

[ctrochalakis]

No unfortunately it doesn't work with master
version[2.0.0-SNAPSHOT], pid[31544], build[76463ee/2014-05-06T08:35:33Z]

I had to enable dynamic scripting for the test to run.

[kimchy]

I will close this for now, sadly, there is nothing we can further do on our side... . We do plan to replace mvel in the near future... . Maybe for now you can try a different language plugin.