[SR-Users] problem with avpops and mongodb modules

Mon Mar 6 09:48:12 CET 2017

>On 22/02/2017 14:35, hsdsdssdfsdf dsasd wrote:
>> I implemented call forwarding according to
>> https://www.kamailio.org/wiki/tutorials/mini-howto-admin/call_forwarding,
>> which is working fine. When I replace db_mysql with db_mongodb
>> however, I receive an error on "if (avp_db_load("$ruri/username",
>> "$avp(s:fwd_blind)")) {":
>>  
>> ERROR: db_mongodb [mongodb_dbase.c:381]: db_mongodb_get_columns():
>> field [attribute] not found in result iterator
>> ERROR: db_mongodb [mongodb_dbase.c:739]: db_mongodb_store_result():
>> failed to set the columns
>> ERROR: db_mongodb [mongodb_dbase.c:918]: db_mongodb_query(): failed to
>> store result
>> ERROR: db_mongodb [mongodb_dbase.c:927]: db_mongodb_query(): failed to
>> do the query
>> ERROR: avpops [avpops_impl.c:381]: ops_dbload_avps(): db_load failed
>can you set debug=3 in kamailio.cfg, restart kamailio and test again?
>Then grab the log messages from syslog and send them here. It should
>provide more debug information.
>
>Is there a record for this query? Or should be an empty response (no
>record returned)?
>
>Cheers,
>Daniel

I used the following to store a forward:
        avp_db_store("$from/username","$avp(s:fwd_blind)");

Which in this case resulted in (after replacing the true forward info):
        > db.usr_preferences.find()
        { "_id" : ObjectId("58ac40f7e498420e0703a2e1"), "uuid" : "", "attribute" : "fwd_blind", "value" : "sip:0003 at x.x.x;user=phone", "type" : 0, "username" : "0002", "domain" : null }

After setting:
        debug=3

        ...
        xlog("bla00");
        if (avp_db_load("$ruri/username", "$avp(s:fwd_blind)")) {
                xlog("bla01"
                ...
        }
        xlog("bla02");
        ...

The syslog shows (after replacing the true username):
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: ERROR: <script>: bla00
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:851]: db_mongodb_query(): query to collection [usr_preferences]
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:885]: db_mongodb_query(): query filter: { "username" : "0002", "attribute" : "fwd_blind" }
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:904]: db_mongodb_query(): columns filter: { "value" : 1, "attribute" : 1, "type" : 1 }
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fa03e54a6a0
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:349]: db_mongodb_get_columns(): 3 columns returned from the query
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 24 bytes for result names at 0x7fa03e54a798
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 12 bytes for result types at 0x7fa03e549848
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[0] named: value
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:396]: db_mongodb_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fa03e549798
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:431]: db_mongodb_get_columns(): use DB1_STRING result type
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:460]: db_mongodb_get_columns(): RES_NAMES(0x7fa03e549798)[0]=[value] (2)
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: db_mongodb [mongodb_dbase.c:377]: db_mongodb_get_columns(): Found a field[1] named: attribute
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: ERROR: db_mongodb [mongodb_dbase.c:381]: db_mongodb_get_columns(): field [attribute] not found in result iterator
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: ERROR: db_mongodb [mongodb_dbase.c:739]: db_mongodb_store_result(): failed to set the columns
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: ERROR: db_mongodb [mongodb_dbase.c:918]: db_mongodb_query(): failed to store result
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: ERROR: db_mongodb [mongodb_dbase.c:927]: db_mongodb_query(): failed to do the query
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 3 columns
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fa03e549798
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fa03e54a798
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fa03e549848
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fa03e54a6a0
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: ERROR: avpops [avpops_impl.c:381]: ops_dbload_avps(): db_load failed
        Feb 24 10:42:18 slb04 /usr/local/sbin/kamailio[20311]: ERROR: <script>: bla02

When changing to db_mysql the error does not occur. I got the following record there:
        MariaDB [kamailio]> select * from usr_preferences;
        +----+------+-------------+--------+-----------+------+-------------------------------------------+---------------------+
        | id | uuid | username    | domain | attribute | type | value                                     | last_modified       |
        +----+------+-------------+--------+-----------+------+-------------------------------------------+---------------------+
        | 26 |      | 0002        |        | fwd_blind |    0 | sip:0003 at x.x.x;user=phone                 | 1900-01-01 00:00:01 |
        +----+------+-------------+--------+-----------+------+-------------------------------------------+---------------------+

With the same kamailio.cfg (except for replacing mongodb with mysql) resulting in:

Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: ERROR: <script>: bla00
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fd17c349800                                                     
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:66]: db_mysql_get_columns(): 3 columns returned from the query
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 24 bytes for result names at 0x7fd17c32f400
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 12 bytes for result types at 0x7fd17c33fae8
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fd17c349350
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7fd17c349350)[0]=[value]
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:135]: db_mysql_get_columns(): use DB1_STRING result type
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7fd17c349458
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7fd17c349458)[1]=[attribute]
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:135]: db_mysql_get_columns(): use DB1_STRING result type
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[2] at 0x7fd17c3493a8
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7fd17c3493a8)[2]=[type]
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: db_mysql [km_res.c:99]: db_mysql_get_columns(): use DB1_INT result type
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:184]: db_allocate_rows(): allocate 16 bytes for rows at 0x7fd17c33fb98
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_row.c:117]: db_allocate_row(): allocate 96 bytes for row values at 0x7fd17c33f778
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_val.c:118]: db_str2val(): converting STRING [sip:0003 at x.x.x;user=phone]
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_val.c:118]: db_str2val(): converting STRING [fwd_blind]
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_val.c:74]: db_str2val(): converting INT [0]
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: avpops [avpops_impl.c:132]: dbrow2avp(): db_flags=3, flags=12
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: avpops [avpops_db.c:265]: db_close_query(): close avp query
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 3 columns
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fd17c349350
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7fd17c349458
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[2] at 0x7fd17c3493a8
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fd17c32f400
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fd17c33fae8
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:52]: db_free_rows(): freeing 1 rows
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_row.c:95]: db_free_row(): freeing row values at 0x7fd17c33f778
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:60]: db_free_rows(): freeing rows at 0x7fd17c33fb98
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fd17c349800
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: DEBUG: avpops [avpops_impl.c:415]: ops_dbload_avps(): loaded avps = 1
Feb 24 11:27:51 slb04 /usr/local/sbin/kamailio[21056]: ERROR: <script>: bla01