#650 db_mysql: Commands out of sync

1.10.x
open
modules (454)
5
2013-07-15
2013-04-29
Ovidiu Sas
No

Opensips started to throw out this errors:
ERROR:db_mysql:db_mysql_do_prepared_query: mysql_stmt_store_result() failed: Commands out of sync; you can't run this command now (2014)
ERROR:usrloc:db_update_ucontact: updating database failed
ERROR:usrloc:update_ucontact: failed to update database

It is only one single process that is constantly throwing out this error. All other process are able to use the db.

There was another process that had a similar issue, but it cleared out. That process had a different error:
ERROR:db_mysql:db_mysql_do_prepared_query: mysql_stmt_store_result() failed: Commands out of sync; you can't run this command now (2014)
ERROR:auth_db:get_ha1: failed to query database

It seems that on a query, the system is able to recover, but on an insert, the system fails to recover,

This is on latest 1.9 svn: svnrevision: 2:9980M

Regards,
Ovidiu Sas

Discussion

  • Ovidiu Sas
    Ovidiu Sas
    2013-04-29

    Here are some updates:
    After aprox 6h1/2, the process with issues recovered while processing a request different then REGISTER:
    INFO:db_mysql:switch_state_to_disconnected: disconnect event for 0x2ae4584ea8c0
    INFO:db_mysql:reset_all_statements: reseting all statements on connection: (0x2ae458566b98) 0x2ae4584ea8c0
    INFO:db_mysql:connect_with_retry: re-connected successful for 0x2ae4584ea8c0

    Regards,
    Ovidiu Sas

     
  • Hello,

    Seems there is a module that doesn't do proper error handling in case of an error for a select query, and it doesn't properly free the result set after the query. Thus all subsequent queries attempted on that connection ( shared by all modules for a particular process ) will fail, since freeing the result for a select query is mandatory before trying to run any other queries on a connection. On reconnection this will auto-magically fix itself, since the old result will be purged by the mysqlclient lib.

    I'll prepare a patch for this, that will print the module and query that didn't get properly freed, so we can trace this bug.
    In your logs, before you start seeing the 'Commands out of sync' errors, do you notice any other ( non-db related perhaps ) errors for that process ?

    Best Regards,
    Vlad

     
    • assigned_to: nobody --> vladut-paiu
     
  • Ovidiu Sas
    Ovidiu Sas
    2013-05-07

    The module that is throwing those errors is usrloc.
    Those errors were printed out while handling REGISTER and saving location.

    Before that, the same process properly handled REGISTERs and there were no other errors or warnings before (in any opensips process).

     
  • Ovidiu Sas
    Ovidiu Sas
    2013-05-07

    Here's the list of modules with db access that are used:
    "usrloc"
    "auth_db"
    "dispatcher"
    "dialplan"
    "pua"
    "presence"

     
  • Ovidiu Sas
    Ovidiu Sas
    2013-06-01

    Any updates on this?
    It started to happen again.

     
  • joelk
    joelk
    2013-06-27

    Any Update? I have the same issue with Opensips 1.9.1 with db_mode=1 (usrloc module)

     
  • Ovidiu Sas
    Ovidiu Sas
    2013-07-09

    On a different setup I experienced a different issue (on usrloc module):
    CRITICAL:db_mysql:wrapper_single_mysql_stmt_execute: driver error (2057): The number of columns in the result set differs from the number of bound buffers. You must reset the statement, rebind the result set columns, and execute the statement again
    ERROR:auth_db:get_ha1: failed to query database

    Other db queries are still working ok.

     
  • Ovidiu Sas
    Ovidiu Sas
    2013-07-09

    What is interesting, is that sometimes the system is able to recover (the next REGISTER is handled ok) and sometimes it is not able to recover from it.

    On the previous post I wanted to say auth_db module instead of usrloc.

     
  • Hello,

    There was a recently fixed bug in auth_db, which seems might be the cause of this.

    Could you please update to the most recent version ( fix was applied on 1.8, 1.9 and trunk ) and let us know if the statement issues continue to appear ?

    Best Regards,
    Vlad

     
  • Ovidiu Sas
    Ovidiu Sas
    2013-07-11

    I was running svn version 10108.
    The official repo is now at 10110 (the running version is missing only the latest cachedb_mongodb documentation updates).

     
  • Ovidiu Sas
    Ovidiu Sas
    2013-07-11

    I don't think that is the same issue as described here:
    https://github.com/OpenSIPS/opensips/issues/6

    The authentication is not using precalculated HA (plain passwords instead).
    And the error points to a failed db query.

     
  • joelk
    joelk
    2013-07-15

    What about the issue on usrloc module?

    I had to use db_mode=0 to avoid opensips crash (cf bug 623) or db desynchro (ie: expired contacts which are still in location table and cannot be deleted by opensips)