ipsilon

Clone
Source Code
GIT

#346 Tracebacks when using ipsilon on RHEL8 with mysql
Opened 4 years ago by arrfab. Modified 3 years ago

Open
Close issue as:
Invalid Insufficient data Fixed Duplicate

Ipsilon works ok to let people being authenticated but in the logs we see this :

version : ipsilon-2.1.0-14.git20200618.c90a76b.el8.noarch

[Wed Nov 18 15:24:24.475768 2020] [wsgi:error] [pid 335055:tid 140091951666944] 
[Wed Nov 18 15:24:24.475770 2020] [wsgi:error] [pid 335055:tid 140091951666944] Traceback (most recent call last):
[Wed Nov 18 15:24:24.475773 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/threading.py", line 916, in _bootstrap_inner
[Wed Nov 18 15:24:24.475775 2020] [wsgi:error] [pid 335055:tid 140091951666944]     self.run()
[Wed Nov 18 15:24:24.475777 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib/python3.6/site-packages/cherrypy/process/plugins.py", line 517, in run
[Wed Nov 18 15:24:24.475779 2020] [wsgi:error] [pid 335055:tid 140091951666944]     self.function(*self.args, **self.kwargs)
[Wed Nov 18 15:24:24.475782 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib/python3.6/site-packages/ipsilon/util/data.py", line 760, in _maybe_run_cleanup
[Wed Nov 18 15:24:24.475784 2020] [wsgi:error] [pid 335055:tid 140091951666944]     auto_removed_entries = self._auto_cleanup()
[Wed Nov 18 15:24:24.475786 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib/python3.6/site-packages/ipsilon/util/data.py", line 783, in _auto_cleanup
[Wed Nov 18 15:24:24.475789 2020] [wsgi:error] [pid 335055:tid 140091951666944]     cleaned_table = q.perform_auto_cleanup()
[Wed Nov 18 15:24:24.475791 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib/python3.6/site-packages/ipsilon/util/data.py", line 276, in perform_auto_cleanup
[Wed Nov 18 15:24:24.475793 2020] [wsgi:error] [pid 335055:tid 140091951666944]     return d.execute().rowcount
[Wed Nov 18 15:24:24.475795 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/sql/base.py", line 411, in execute
[Wed Nov 18 15:24:24.475798 2020] [wsgi:error] [pid 335055:tid 140091951666944]     return e._execute_clauseelement(self, multiparams, params)
[Wed Nov 18 15:24:24.475800 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 2173, in _execute_clauseelement
[Wed Nov 18 15:24:24.475802 2020] [wsgi:error] [pid 335055:tid 140091951666944]     return connection._execute_clauseelement(elem, multiparams, params)
[Wed Nov 18 15:24:24.475805 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1107, in _execute_clauseelement
[Wed Nov 18 15:24:24.475807 2020] [wsgi:error] [pid 335055:tid 140091951666944]     distilled_params,
[Wed Nov 18 15:24:24.475809 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
[Wed Nov 18 15:24:24.475812 2020] [wsgi:error] [pid 335055:tid 140091951666944]     e, statement, parameters, cursor, context
[Wed Nov 18 15:24:24.475820 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1466, in _handle_dbapi_exception
[Wed Nov 18 15:24:24.475823 2020] [wsgi:error] [pid 335055:tid 140091951666944]     util.raise_from_cause(sqlalchemy_exception, exc_info)
[Wed Nov 18 15:24:24.475825 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 383, in raise_from_cause
[Wed Nov 18 15:24:24.475828 2020] [wsgi:error] [pid 335055:tid 140091951666944]     reraise(type(exception), exception, tb=exc_tb, cause=cause)
[Wed Nov 18 15:24:24.475830 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 128, in reraise
[Wed Nov 18 15:24:24.475832 2020] [wsgi:error] [pid 335055:tid 140091951666944]     raise value.with_traceback(tb)
[Wed Nov 18 15:24:24.475834 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
[Wed Nov 18 15:24:24.475837 2020] [wsgi:error] [pid 335055:tid 140091951666944]     cursor, statement, parameters, context
[Wed Nov 18 15:24:24.475839 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
[Wed Nov 18 15:24:24.475847 2020] [wsgi:error] [pid 335055:tid 140091951666944]     cursor.execute(statement, parameters)
[Wed Nov 18 15:24:24.475850 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 209, in execute
[Wed Nov 18 15:24:24.475852 2020] [wsgi:error] [pid 335055:tid 140091951666944]     res = self._query(query)
[Wed Nov 18 15:24:24.475854 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 315, in _query
[Wed Nov 18 15:24:24.475856 2020] [wsgi:error] [pid 335055:tid 140091951666944]     db.query(q)
[Wed Nov 18 15:24:24.475859 2020] [wsgi:error] [pid 335055:tid 140091951666944]   File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 239, in query
[Wed Nov 18 15:24:24.475861 2020] [wsgi:error] [pid 335055:tid 140091951666944]     _mysql.connection.query(self, query)
[Wed Nov 18 15:24:24.475863 2020] [wsgi:error] [pid 335055:tid 140091951666944] sqlalchemy.exc.OperationalError: (MySQLdb._exceptions.OperationalError) (1093, "You can't specify target table 'saml2_sessions' for update in FROM clause")
[Wed Nov 18 15:24:24.475866 2020] [wsgi:error] [pid 335055:tid 140091951666944] [SQL: DELETE FROM saml2_sessions WHERE saml2_sessions.uuid IN (SELECT saml2_sessions.uuid 
[Wed Nov 18 15:24:24.475868 2020] [wsgi:error] [pid 335055:tid 140091951666944] FROM saml2_sessions 
[Wed Nov 18 15:24:24.475871 2020] [wsgi:error] [pid 335055:tid 140091951666944] WHERE saml2_sessions.name = %s AND saml2_sessions.value <= %s)]
[Wed Nov 18 15:24:24.475873 2020] [wsgi:error] [pid 335055:tid 140091951666944] [parameters: ('expiration_time', '2020-11-18 15:24:24.474023')]
[Wed Nov 18 15:24:24.475875 2020] [wsgi:error] [pid 335055:tid 140091951666944] (Background on this error at: http://sqlalche.me/e/e3q8)
[Wed Nov 18 15:24:24.475883 2020] [wsgi:error] [pid 335055:tid 140091951666944] 
[Wed Nov 18 15:24:24.497535 2020] [wsgi:error] [pid 335055:tid 140091934881536] Exception in thread Thread-5:
[Wed Nov 18 15:24:24.497557 2020] [wsgi:error] [pid 335055:tid 140091934881536] Traceback (most recent call last):
[Wed Nov 18 15:24:24.497560 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
[Wed Nov 18 15:24:24.497563 2020] [wsgi:error] [pid 335055:tid 140091934881536]     cursor, statement, parameters, context
[Wed Nov 18 15:24:24.497565 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
[Wed Nov 18 15:24:24.497573 2020] [wsgi:error] [pid 335055:tid 140091934881536]     cursor.execute(statement, parameters)
[Wed Nov 18 15:24:24.497575 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 209, in execute
[Wed Nov 18 15:24:24.497577 2020] [wsgi:error] [pid 335055:tid 140091934881536]     res = self._query(query)
[Wed Nov 18 15:24:24.497580 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 315, in _query
[Wed Nov 18 15:24:24.497582 2020] [wsgi:error] [pid 335055:tid 140091934881536]     db.query(q)
[Wed Nov 18 15:24:24.497584 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 239, in query
[Wed Nov 18 15:24:24.497587 2020] [wsgi:error] [pid 335055:tid 140091934881536]     _mysql.connection.query(self, query)
[Wed Nov 18 15:24:24.497589 2020] [wsgi:error] [pid 335055:tid 140091934881536] MySQLdb._exceptions.OperationalError: (1093, "You can't specify target table 'transactions' for update in FROM clause")
[Wed Nov 18 15:24:24.497592 2020] [wsgi:error] [pid 335055:tid 140091934881536] 
[Wed Nov 18 15:24:24.497601 2020] [wsgi:error] [pid 335055:tid 140091934881536] The above exception was the direct cause of the following exception:
[Wed Nov 18 15:24:24.497604 2020] [wsgi:error] [pid 335055:tid 140091934881536] 
[Wed Nov 18 15:24:24.497606 2020] [wsgi:error] [pid 335055:tid 140091934881536] Traceback (most recent call last):
[Wed Nov 18 15:24:24.497608 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/threading.py", line 916, in _bootstrap_inner
[Wed Nov 18 15:24:24.497611 2020] [wsgi:error] [pid 335055:tid 140091934881536]     self.run()
[Wed Nov 18 15:24:24.497613 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib/python3.6/site-packages/cherrypy/process/plugins.py", line 517, in run
[Wed Nov 18 15:24:24.497615 2020] [wsgi:error] [pid 335055:tid 140091934881536]     self.function(*self.args, **self.kwargs)
[Wed Nov 18 15:24:24.497618 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib/python3.6/site-packages/ipsilon/util/data.py", line 760, in _maybe_run_cleanup
[Wed Nov 18 15:24:24.497620 2020] [wsgi:error] [pid 335055:tid 140091934881536]     auto_removed_entries = self._auto_cleanup()
[Wed Nov 18 15:24:24.497622 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib/python3.6/site-packages/ipsilon/util/data.py", line 783, in _auto_cleanup
[Wed Nov 18 15:24:24.497625 2020] [wsgi:error] [pid 335055:tid 140091934881536]     cleaned_table = q.perform_auto_cleanup()
[Wed Nov 18 15:24:24.497627 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib/python3.6/site-packages/ipsilon/util/data.py", line 276, in perform_auto_cleanup
[Wed Nov 18 15:24:24.497629 2020] [wsgi:error] [pid 335055:tid 140091934881536]     return d.execute().rowcount
[Wed Nov 18 15:24:24.497632 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/sql/base.py", line 411, in execute
[Wed Nov 18 15:24:24.497634 2020] [wsgi:error] [pid 335055:tid 140091934881536]     return e._execute_clauseelement(self, multiparams, params)
[Wed Nov 18 15:24:24.497636 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 2173, in _execute_clauseelement
[Wed Nov 18 15:24:24.497639 2020] [wsgi:error] [pid 335055:tid 140091934881536]     return connection._execute_clauseelement(elem, multiparams, params)
[Wed Nov 18 15:24:24.497641 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1107, in _execute_clauseelement
[Wed Nov 18 15:24:24.497643 2020] [wsgi:error] [pid 335055:tid 140091934881536]     distilled_params,
[Wed Nov 18 15:24:24.497646 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
[Wed Nov 18 15:24:24.497650 2020] [wsgi:error] [pid 335055:tid 140091934881536]     e, statement, parameters, cursor, context
[Wed Nov 18 15:24:24.497653 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1466, in _handle_dbapi_exception
[Wed Nov 18 15:24:24.497655 2020] [wsgi:error] [pid 335055:tid 140091934881536]     util.raise_from_cause(sqlalchemy_exception, exc_info)
[Wed Nov 18 15:24:24.497658 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 383, in raise_from_cause
[Wed Nov 18 15:24:24.497660 2020] [wsgi:error] [pid 335055:tid 140091934881536]     reraise(type(exception), exception, tb=exc_tb, cause=cause)
[Wed Nov 18 15:24:24.497662 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 128, in reraise
[Wed Nov 18 15:24:24.497665 2020] [wsgi:error] [pid 335055:tid 140091934881536]     raise value.with_traceback(tb)
[Wed Nov 18 15:24:24.497667 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
[Wed Nov 18 15:24:24.497669 2020] [wsgi:error] [pid 335055:tid 140091934881536]     cursor, statement, parameters, context
[Wed Nov 18 15:24:24.497671 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
[Wed Nov 18 15:24:24.497674 2020] [wsgi:error] [pid 335055:tid 140091934881536]     cursor.execute(statement, parameters)
[Wed Nov 18 15:24:24.497676 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 209, in execute
[Wed Nov 18 15:24:24.497678 2020] [wsgi:error] [pid 335055:tid 140091934881536]     res = self._query(query)
[Wed Nov 18 15:24:24.497681 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/MySQLdb/cursors.py", line 315, in _query
[Wed Nov 18 15:24:24.497683 2020] [wsgi:error] [pid 335055:tid 140091934881536]     db.query(q)
[Wed Nov 18 15:24:24.497685 2020] [wsgi:error] [pid 335055:tid 140091934881536]   File "/usr/lib64/python3.6/site-packages/MySQLdb/connections.py", line 239, in query
[Wed Nov 18 15:24:24.497688 2020] [wsgi:error] [pid 335055:tid 140091934881536]     _mysql.connection.query(self, query)
[Wed Nov 18 15:24:24.497690 2020] [wsgi:error] [pid 335055:tid 140091934881536] sqlalchemy.exc.OperationalError: (MySQLdb._exceptions.OperationalError) (1093, "You can't specify target table 'transactions' for update in FROM clause")
[Wed Nov 18 15:24:24.497693 2020] [wsgi:error] [pid 335055:tid 140091934881536] [SQL: DELETE FROM transactions WHERE transactions.uuid IN (SELECT transactions.uuid 
[Wed Nov 18 15:24:24.497695 2020] [wsgi:error] [pid 335055:tid 140091934881536] FROM transactions 
[Wed Nov 18 15:24:24.497697 2020] [wsgi:error] [pid 335055:tid 140091934881536] WHERE transactions.name = %s AND transactions.value <= %s)]
[Wed Nov 18 15:24:24.497699 2020] [wsgi:error] [pid 335055:tid 140091934881536] [parameters: ('expiration_time', '2020-11-18 15:24:24.495912')]
[Wed Nov 18 15:24:24.497702 2020] [wsgi:error] [pid 335055:tid 140091934881536] (Background on this error at: http://sqlalche.me/e/e3q8)
[Wed Nov 18 15:24:24.497709 2020] [wsgi:error] [pid 335055:tid 140091934881536]

So, this is a query that's executed for the regular cleanup, so while users would be logging in succesfully, it means that the transactions table grows without bounds on every login transaction.
This seems to be because of some silliness in MySQL, and can be resolved by having another select inside the inner select.
I may take a look later this week for a fix, unless someone else gets to it first.

Metadata Update from @puiterwijk:
- Custom field component adjusted to None
- Custom field type adjusted to None
- Custom field version adjusted to None
4 years ago

Metadata Update from @puiterwijk:
- Custom field component adjusted to framework (was: None)
- Custom field type adjusted to defect (was: None)
4 years ago

Probably related but we have now zillions of .lock files under /var/lib/ipsilon/idp/sessions.
So wondering if we can fix that easily as it's also eating all inodes on the filesystem
When restarting node and httpd : 

[Tue Apr 06 06:05:11.223072 2021] [wsgi:error] [pid 310125:tid 140278429943552] Exception in thread Thread-1:
[Tue Apr 06 06:05:11.223142 2021] [wsgi:error] [pid 310125:tid 140278429943552] Traceback (most recent call last):
[Tue Apr 06 06:05:11.223218 2021] [wsgi:error] [pid 310125:tid 140278429943552]   File "/usr/lib64/python3.6/threading.py", line 916, in _bootstrap_inner
[Tue Apr 06 06:05:11.228965 2021] [wsgi:error] [pid 310125:tid 140278429943552]     self.run()
[Tue Apr 06 06:05:11.229694 2021] [wsgi:error] [pid 310125:tid 140278429943552]   File "/usr/lib/python3.6/site-packages/cherrypy/process/plugins.py", line 517, in run
[Tue Apr 06 06:05:11.229706 2021] [wsgi:error] [pid 310125:tid 140278429943552]     self.function(*self.args, **self.kwargs)
[Tue Apr 06 06:05:11.229711 2021] [wsgi:error] [pid 310125:tid 140278429943552]   File "/usr/lib/python3.6/site-packages/ipsilon/util/data.py", line 765, in _maybe_run_cle
anup
[Tue Apr 06 06:05:11.229716 2021] [wsgi:error] [pid 310125:tid 140278429943552]     removed_entries = self._cleanup()
[Tue Apr 06 06:05:11.230388 2021] [wsgi:error] [pid 310125:tid 140278429943552]   File "/usr/lib/python3.6/site-packages/ipsilon/providers/openidc/store.py", line 402, in 
_cleanup
[Tue Apr 06 06:05:11.230921 2021] [wsgi:error] [pid 310125:tid 140278429943552]     res1 = self._cleanupExpiredTokens()
[Tue Apr 06 06:05:11.230950 2021] [wsgi:error] [pid 310125:tid 140278429943552]   File "/usr/lib/python3.6/site-packages/ipsilon/providers/openidc/store.py", line 387, in 
_cleanupExpiredTokens
[Tue Apr 06 06:05:11.231085 2021] [wsgi:error] [pid 310125:tid 140278429943552]     if tokens[iden]['expires_at'] <= int(time.time()):
[Tue Apr 06 06:05:11.231315 2021] [wsgi:error] [pid 310125:tid 140278429943552] TypeError: '<=' not supported between instances of 'str' and 'int'

Log in to comment on this ticket.

Metadata
None
None
None
None
None
None
None
defect
framework
None
None
None
Powered by Pagure 5.14.1
Documentation • File an Issue • About • SSH Hostkey/Fingerprint
© Red Hat, Inc. and others.