search

OpenSIPS / opensips-cli

OpenSIPS CLI tool - an interactive command line tool that can be used to control and monitor OpenSIPS servers.
GNU General Public License v3.0
85 stars 48 forks source link

Error on database create: Unable to lock control file /var/lib/mysql/aria_log_control #63

Closed carels closed 4 years ago

carels commented 4 years ago

Hi,

I am unable to run the database create command when setting up opensips with opensips-cli. I first get this error:

Got ERROR: "unknown: Can't lock aria control file '/var/lib/mysql/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds" errno: 2000

Followed by loads of: Got ERROR: "InnoDB: Unable to lock /var/lib/mysql/ibdata1 error: 11" errno: 2000

and eventually an error with a traceback: Got ERROR: "Could not open mysql.plugin table. Some plugins may be not loaded" errno: 2000

Any suggestions on the possible cause?

Thanks Carel

opensips -V version: opensips 3.0.2 (x86_64/linux) flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, HP_MALLOC, DBG_MALLOC, FAST_LOCK-ADAPTIVE_WAIT ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 poll method support: poll, epoll, sigio_rt, select. git revision: 7e8167853 main.c compiled on 06:54:45 Jun 26 2020 with gcc 4.8.5

opensips-cli -v OpenSIPS CLI 0.1.0

MariaDB [mysql]> select @@version; +-----------------+ | @@version | +-----------------+ | 10.4.13-MariaDB | +-----------------+ 1 row in set (0.001 sec)

cat /etc/redhat-release

CentOS Linux release 7.8.2003 (Core)

python --version

Python 3.6.8

Output: DEBUG: Loaded module 'database' DEBUG: Loaded module 'diagnose' DEBUG: Loaded module 'instance' DEBUG: fifo file /tmp/opensips_fifo does not exist! DEBUG: Skipping module 'mi' - excluded on purpose DEBUG: Loaded module 'tls' DEBUG: Loaded module 'trace' DEBUG: Loaded module 'trap' DEBUG: Loaded module 'user' DEBUG: running in non-interactive mode '['database', 'create']' DEBUG: running command 'create' '[]' DEBUG: db_name: 'opensips' DEBUG: read password: '**' DEBUG: admin DB URL: 'mysql://root:**@localhost' DEBUG: connecting to mysql://root:**@localhost Got ERROR: "unknown: Can't lock aria control file '/var/lib/mysql/aria_log_control' for exclusive use, error: 11. Will retry for 30 seconds" errno: 2000 Got ERROR: "unknown: Got error 'Could not get an exclusive lock; file is probably in use by another process' when trying to use aria control file '/var/lib/mysql/aria_log_control'" errno: 2000 Got ERROR: "Plugin 'Aria' init function returned error." errno: 2000 Got ERROR: "Plugin 'Aria' registration as a STORAGE ENGINE failed." errno: 2000 Got ERROR: "InnoDB: Unable to lock /var/lib/mysql/ibdata1 error: 11" errno: 2000 Got ERROR: "InnoDB: Unable to lock /var/lib/mysql/ibdata1 error: 11" errno: 2000 ... approx 100 lines of InnoDB Unable to lock... ... Got ERROR: "InnoDB: Unable to lock /var/lib/mysql/ibdata1 error: 11" errno: 2000 Got ERROR: "InnoDB: Operating system error number 11 in a file operation." errno: 2000 Got ERROR: "InnoDB: Error number 11 means 'Resource temporarily unavailable'" errno: 2000 Got ERROR: "InnoDB: Cannot open datafile '/var/lib/mysql/ibdata1'" errno: 2000 Got ERROR: "InnoDB: Could not open or create the system tablespace. If you tried to add new data files to the system tablespace, and it failed here, you should now edit innodb_data_file_path in my.cnf back to what it was, and remove the new ibdata files InnoDB created i n this failed attempt. InnoDB only wrote those files full of zeros, but did not yet use them in any way. But be careful: do not remove old data files which contain your precious data!" errno: 2000 Got ERROR: "InnoDB: Plugin initialization aborted with error Cannot open a file" errno: 2000 Got ERROR: "Plugin 'InnoDB' init function returned error." errno: 2000 Got ERROR: "Plugin 'InnoDB' registration as a STORAGE ENGINE failed." errno: 2000 Got ERROR: "Could not open mysql.plugin table. Some plugins may be not loaded" errno: 2000 Got ERROR: "Failed to initialize plugins." errno: 2000 Traceback (most recent call last): File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 2262, in _wrap_pool_connect return fn() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 303, in unique_connection return _ConnectionFairy._checkout(self) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 760, in _checkout fairy = _ConnectionRecord.checkout(pool) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 492, in checkout rec = pool._do_get() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/impl.py", line 139, in _do_get self._dec_overflow() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/util/langhelpers.py", line 68, in exit compat.reraise(exc_type, exc_value, exc_tb) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 129, in reraise raise value File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/impl.py", line 136, in _do_get return self._create_connection() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 308, in _create_connection return _ConnectionRecord(self) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 437, in init self.connect(first_connect_check=True) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 639, in __connect connection = pool._invoke_creator(self) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/strategies.py", line 114, in connect return dialect.connect(*cargs, *cparams) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/default.py", line 453, in connect return self.dbapi.connect(cargs, **cparams) File "/usr/local/lib/python3.6/site-packages/mysqlclient-1.3.14-py3.6-linux-x86_64.egg/MySQLdb/init__.py", line 85, in Connect return Connection(*args, **kwargs) File "/usr/local/lib/python3.6/site-packages/mysqlclient-1.3.14-py3.6-linux-x86_64.egg/MySQLdb/connections.py", line 192, in init client_version = tuple([ numeric_part(n) for n in _mysql.get_client_info().split('.')[:2] ]) _mysql_exceptions.InternalError: (-1, 'server not initialized')

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/usr/local/bin/opensips-cli", line 4, in import('pkg_resources').run_script('opensipscli==0.1.0', 'opensips-cli') File "/usr/lib/python3.6/site-packages/pkg_resources/init.py", line 654, in run_script self.require(requires)[0].run_script(script_name, ns) File "/usr/lib/python3.6/site-packages/pkg_resources/init.py", line 1434, in run_script exec(code, namespace, namespace) File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/EGG-INFO/scripts/opensips-cli", line 9, in run_console() File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/EGG-INFO/scripts/opensips-cli", line 6, in run_console main.main() File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/opensipscli/main.py", line 78, in main sys.exit(shell.cmdloop()) File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/opensipscli/cli.py", line 242, in cmdloop ret = self.run_command(self.command[0], command, params) File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/opensipscli/cli.py", line 357, in run_command return mod[0].invoke(cmd, params) File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/opensipscli/module.py", line 36, in invoke return f(params) File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/opensipscli/modules/database.py", line 369, in do_create admin_db = self.get_db(admin_url, db_name) File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/opensipscli/modules/database.py", line 630, in get_db return osdb(db_url, db_name) File "/usr/local/lib/python3.6/site-packages/opensipscli-0.1.0-py3.6.egg/opensipscli/db.py", line 136, in init self.conn = self.engine.connect().\ File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 2193, in connect return self._connection_cls(self, kwargs) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 103, in init else engine.raw_connection() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 2293, in raw_connection self.pool.unique_connection, _connection File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 2266, in _wrap_pool_connect e, dialect, self File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1536, in _handle_dbapi_exception_noconnection util.raise_from_cause(sqlalchemy_exception, exc_info) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 383, in raise_from_cause reraise(type(exception), exception, tb=exc_tb, cause=cause) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 128, in reraise raise value.with_traceback(tb) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 2262, in _wrap_pool_connect return fn() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 303, in unique_connection return _ConnectionFairy._checkout(self) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 760, in _checkout fairy = _ConnectionRecord.checkout(pool) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 492, in checkout rec = pool._do_get() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/impl.py", line 139, in _do_get self._dec_overflow() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/util/langhelpers.py", line 68, in exit compat.reraise(exc_type, exc_value, exc_tb) compat.reraise(exc_type, exc_value, exc_tb) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 129, in reraise raise value File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/impl.py", line 136, in _do_get return self._create_connection() File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 308, in _create_connection return _ConnectionRecord(self) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 437, in init self.__connect(first_connect_check=True) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/pool/base.py", line 639, in __connect connection = pool._invoke_creator(self) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/strategies.py", line 114, in connect return dialect.connect(*cargs, *cparams) File "/usr/local/lib/python3.6/site-packages/SQLAlchemy-1.3.3-py3.6-linux-x86_64.egg/sqlalchemy/engine/default.py", line 453, in connect return self.dbapi.connect(cargs, cparams) File "/usr/local/lib/python3.6/site-packages/mysqlclient-1.3.14-py3.6-linux-x86_64.egg/MySQLdb/init.py", line 85, in Connect return Connection(*args, **kwargs) File "/usr/local/lib/python3.6/site-packages/mysqlclient-1.3.14-py3.6-linux-x86_64.egg/MySQLdb/connections.py", line 192, in init client_version = tuple([ numeric_part(n) for n in _mysql.get_client_info().split('.')[:2] ]) sqlalchemy.exc.InternalError: (_mysql_exceptions.InternalError) (-1, 'server not initialized') (Background on this error at: http://sqlalche.me/e/2j85)

liviuchircu commented 4 years ago

@carels, the 11 glibc error code means: "Permission denied". So apparently it looks like there is some permissions issue, for example:

WARNING: only if you are playing on a test environment, my suggestion is to either do:

carels commented 4 years ago

Hi Liviu,

I also thought about the permissions, however everything looks ok:

ps auxww | grep -i mysql mysql 3256 0.1 3.2 1305868 123256 ? Ssl 16:05 0:04 /usr/sbin/mysqld

ls -ld /var/lib/mysql/ drwxr-xr-x 15 mysql mysql 4096 Jun 29 16:41 /var/lib/mysql/

ls -l /var/lib/mysql/ total 188604 -rw-rw---- 1 mysql mysql 90112 Jun 29 16:03 aria_log.00000001 -rw-rw---- 1 mysql mysql 52 Jun 29 16:03 aria_log_control -rw-rw---- 1 mysql mysql 5 Jun 29 16:05 dev11.pid -rw-rw---- 1 mysql mysql 14646 Jun 29 16:03 ib_buffer_pool -rw-rw---- 1 mysql mysql 79691776 Jun 29 16:44 ibdata1 -rw-rw---- 1 mysql mysql 50331648 Jun 29 16:44 ib_logfile0 -rw-rw---- 1 mysql mysql 50331648 Jun 29 16:44 ib_logfile1 -rw-rw---- 1 mysql mysql 12582912 Jun 29 16:05 ibtmp1 -rw-rw---- 1 mysql mysql 0 Oct 22 2019 multi-master.info drwx------ 2 mysql mysql 4096 Oct 22 2019 mysql srwxrwxrwx 1 mysql mysql 0 Jun 29 16:05 mysql.sock drwx------ 2 mysql mysql 4096 Oct 22 2019 performance_schema

Regards, Carel

liviuchircu commented 4 years ago

Any additional steps to reproduce this problem besides taking a 7.8 CentOS with MariaDB and opensips-cli packages, then attempting to create the DB? E.g. maybe some particular cfg settings, install methods, a.s.o.

carels commented 4 years ago

I have tried this on a fresh FreePBX ISO install (SNG7-PBX-64bit-2002S). Worked a charm (although, the script failed to create the database user as specified in the config which I had to create manually). Other than the different OS I followed the same installation steps, except for Linux, Python & MySQL versions that are slightly different.

The urgent need is for this in a FPBX environment and since that is working I'll be using that for testing. I will need to build a new dev environment and see if that works, but it will be a bit of time before I will get around to do that. Probably need to write this one down to some version incompatibility or unusual change since the broken install is on a dev box.

Thanks for the assistance!