CODEWITHSUNDEEP
ejabberd
devfubar
devfubar

Reputation: 628

Ejabberd api set_vcard database_failure

When I use the following command for the ejabberd API I get the following response;

curl -ik -X POST -H 'Authorization: Bearer xxxxxxxxxxx' https://localhost:5280/api/set_vcard -d '{"user":"foo","host":"example.com","name":"FN","content":"foobar"}'

HTTP/1.1 400 Bad Request
Content-Length: 18
Content-Type: application/json
Access-Control-Allow-Origin: *
Access-Control-Allow-Headers: Content-Type, Authorization, X-Admin

"database_failure"

On the ejabberd log (level 5) I see this;

[info] (<0.607.0>) Accepted connection ::ffff:172.18.0.1:46622 -> ::ffff:172.18.0.3:5280
[debug] S: [{[<<"ws">>],ejabberd_http_ws},{[<<"bosh">>],mod_bosh},{[<<"oauth">>],ejabberd_oauth},{[<<"api">>],mod_http_api},{[<<"admin">>],ejabberd_web_admin}]
[debug] ({tlssock,#Port<0.18819>,#Ref<0.650175335.3240493057.203147>}) http query: 'POST' <<"/api/set_vcard">>
[debug] client data: <<"{\"user\":\"foo\",\"host\":\"example.com\",\"contents\":[\"FN:foobar\"]}">>
[debug] [<<"api">>,<<"set_vcard">>] matches [<<"api">>]
[info] API call set_vcard [{<<"user">>,<<"foo">>},{<<"host">>,<<"example.com">>},{<<"contents">>,[<<"FN:foobar">>]}] from ::ffff:172.18.0.1:46622
[debug] Command 'set_vcard' execution allowed by rule 'api service' (CallerInfo=#{caller_module => mod_http_api,caller_server => <<"example.com">>,ip => {0,0,0,0,0,65535,44050,1},oauth_scope => [<<"ejabberd:api-service">>],usr => {<<"admin">>,<<"example.com">>,<<>>}})
[debug] Executing command mod_admin_extra:set_vcard with Args=[<<"foo">>,<<"example.com">>,<<>>,<<>>,[<<"FN:foobar">>]]

It is using MySQL as a database (working fine for everything else) however when I watch the database general query log I don't see my API request trigger any queries. I see all the other normal ejabberd queries so there isn't a problem with the db connection and as mentioned earlier everything else works.

$ ejabberdctl status
The node ejabberd@e87da11aa894 is started with status: started
ejabberd 18.4.0 is running in that node

Does anyone have any clues they can throw my way? I've ran out of leads on what could be the issue.

!!! EDIT !!!

Work around

As mentioned in https://github.com/processone/ejabberd/issues/2629 other people have experienced this issue. Changing config to disable the cache and clearing the vcard table in the database seems to be a work around;

SQL:

DELETE FROM vcard;

Config:

...
mod_vcard:
  search: false
  use_cache: false
...

Upvotes: 0

Views: 228

Answers (2)

Leon Wright
Leon Wright

Reputation: 66

The API is fairly permissive in what it allows, however once it's in the database the record will fail to load.

For 'set_vcard', the 'name 'is the field name you wish to alter and the content is the contents of that field.

{
  "user": "catman",
  "host": "the.host",
  "name": "FN",
  "content": "Cat Man"
}

ejabberd also caches queries, so once you have a barfed record it'll return 'database_failed' even if you've corrected your api call or fixed it in the database by hand. Caching can be disabled under the modules configuration.

Upvotes: 1

Badlop
Badlop

Reputation: 4120

Notice in your log that it says:

[debug] client data: <<"{\"user\":\"foo\",\"host\":\"example.com\",\"contents\":[\"FN:foobar\"]}">>

How can it be that contents is FN:foobar? I installed 18.04, setup mysql storage, and running this query:

$ curl -v -H "X-Admin: true" -H "Content-Type:application/json" http://localhost:5280/api/set_vcard -d '{"user":"user1","host":"localhost","name":"FN","content":"mi nombre curllll"}'

The log says:

21:42:29.638 [info] (<0.487.0>) Accepted connection 127.0.0.1:58412 -> 127.0.0.1:5280
21:42:29.638 [debug] S: [{[<<"api">>],mod_http_api},{[<<"bosh">>],mod_bosh},{[<<"oauth">>],ejabberd_oauth},{[<<"presence">>],mod_webpresence},{[<<"register">>],mod_register_web},{[<<"rest">>],mod_rest},{[<<"ws">>],ejabberd_http_ws},{[<<"admin">>],ejabberd_web_admin}]
21:42:29.639 [debug] (#Port<0.18079>) http query: 'POST' <<"/api/set_vcard">>
21:42:29.639 [debug] client data: <<"{\"user\":\"user1\",\"host\":\"localhost\",\"name\":\"FN\",\"content\":\"mi nombre curllll\"}">>
21:42:29.639 [debug] [<<"api">>,<<"set_vcard">>] matches [<<"api">>]
21:42:29.639 [info] API call set_vcard [{<<"user">>,<<"user1">>},{<<"host">>,<<"localhost">>},{<<"name">>,<<"FN">>},{<<"content">>,<<"mi nombre curllll">>}] from 127.0.0.1:58412
21:42:29.640 [debug] Command 'set_vcard' execution allowed by rule 'test commands' (CallerInfo=#{caller_module => mod_http_api,ip => {127,0,0,1}})
21:42:29.640 [debug] Executing command mod_admin_extra:set_vcard with Args=[<<"user1">>,<<"localhost">>,<<"FN">>,<<"mi nombre curllll">>] 
21:42:29.640 [debug] SQL: "select vcard from vcard where username='user1' and 0=0"
21:42:29.642 [debug] SQL: "begin;"
21:42:29.642 [debug] SQL: "UPDATE vcard SET vcard='<vCard xmlns=''vcard-temp''><FN>mi nombre curllll</FN><N><FAMILY>mi familia11</FAMILY></N><NICKNAME>mi apodoooooooooooooooooooo11</NICKNAME><PHOTO><BINVAL>R0lGODlhDwAPAJECAP//AAAAAP///wAAACH5BAEAAAIALAAAAAAPAA8AAAIulB2Zx5IA4WIhWnnqvQFJDTyhE4khaG5Wqn4tp4ErFnMY+Sll9naUfGpkFL5DAQA7</BINVAL><TYPE>image/gif</TYPE></PHOTO></vCard>' WHERE username='user1'"
21:42:29.644 [debug] SQL: "UPDATE vcard_search SET username='user1', fn='mi nombre curllll', lfn='mi nombre curllll', family='mi familia11', lfamily='mi familia11', given='', lgiven='', middle='', lmiddle='', nickname='mi apodoooooooooooooooooooo11', lnickname='mi apodoooooooooooooooooooo11', bday='', lbday='', ctry='', lctry='', locality='', llocality='', email='', lemail='', orgname='', lorgname='', orgunit='', lorgunit='' WHERE lusername='user1'"
21:42:29.658 [debug] SQL: "commit;"

Upvotes: 0

Related Questions