Project

General

Profile

Support #3967

Server 500 error

Added by Marcin Kuzminski [staff] about 3 years ago. Updated about 3 years ago.

Status:
In Progress
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
01.06.2016
Due date:
% Done:

0%

Estimated time:
Sorting:
Commit Number:
Affected Version:

Description

[tenderapp] report: https://rhodecode.tenderapp.com/help/discussions/support-tickets/1766 reported by user: craig@avsdev.uk

Hello,

I've been getting a server 500 error with RhodeCode. Apache displays
nothing in its error log (with full logging enabled) and I receive
emails from the instance with the really unhelpful:

SQLAlchemy: 2006 'MySQL server has gone away'

The MySQL server has not 'gone away' (I am aware that it is one of the
most ambiguous errors in MySQL), the user account RhodeCode is running
under does have permissions and the configuration file has the correct
url (localhost server, port 3306), username and password.

Celery is not in use at the moment but I would like to eventually enable it.

For some reason it appears to affect every other page load (ie if I
refresh a page it loads, but if I refresh it second time it fails).
Visiting a new page causes it to fail the first time every time.

I should also point out that I have an older version running on another
server that I have no issues with - both of the servers are the same
build, same version of debian (jessie) and have identical packages with
the exception of the version of RhodeCode and the Apache server alias.

I basically have no more ideas and I'm one step short of giving it up as
a bad job and re-building the server - if you could prevent this I would
be grateful.

Regards,
Craig Williams

History

#1 Updated by Marcin Kuzminski [staff] about 3 years ago

Hi Craig,

What version are you using currently ? It's somehow known problem, and if it;s not mysql problem itself we usually fixed it by setting pool_recycle inside the ini file:
https://code.rhodecode.com/rhodecode-enterprise-ce/files/e0af06ce5559c7cdd1359f33a681ca6c73e35bae/configs/development.ini#L462

and for beaker sessions as well:

https://code.rhodecode.com/rhodecode-enterprise-ce/files/e0af06ce5559c7cdd1359f33a681ca6c73e35bae/configs/development.ini#L343

#2 Updated by Marcin Kuzminski [staff] about 3 years ago

  • Private changed from Yes to No

#3 Updated by Mihai Nica about 3 years ago

Hi Marcin,

I might have the same issue as Craig. Anyway, thought it would be better to update this issue instead of opening a new one.
Already checked the pool_recycle, and it's set.
Her
Here is the information in the error log:

2016-08-11 08:48:37.672 ERROR [rhodecode.lib.caches] Failed to commit on cache key update
Traceback (most recent call last):
  File "/opt/rhodecode/store/0lg6aqzs7b4bs1x12s8i6ib5hqa285rj-python2.7-rhodecode-enterprise-ce-4.2.1/lib/python2.7/site-packages/rhodecode/lib/caches.py", line 216, in __exit__
    Session().commit()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 788, in commit
    self.transaction.commit()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 384, in commit
    self._prepare_impl()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 364, in _prepare_impl
    self.session.flush()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1985, in flush
    self._flush(objects)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 2103, in _flush
    transaction.rollback(_capture_exception=True)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
    compat.reraise(exc_type, exc_value, exc_tb)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 2067, in _flush
    flush_context.execute()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
    rec.execute(self)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 526, in execute
    uow
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 65, in save_obj
    mapper, table, insert)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 602, in _emit_insert_statements
    execute(statement, params)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 841, in execute
    return meth(self, multiparams, params)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 938, in _execute_clauseelement
    compiled_sql, distilled_params
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1005, in _execute_context
    None, None)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1271, in _handle_dbapi_exception
    exc_info
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 999, in _execute_context
    conn = self._revalidate_connection()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 354, in _revalidate_connection
"Can't reconnect until invalid "
StatementError: Can't reconnect until invalid transaction is rolled back (original cause: InvalidRequestError: Can't reconnect until invalid transaction is rolled back) u'INSERT INTO cache_invalidation (cache_key, cache_args, cache_active) VALUES (%s, %s, %s)' [{'cache_active': True, 'cache_args': u'wsys/linux-tools/backup', 'cache_key': u'vcs-14268wsys/linux-tools/backup'}]
2016-08-11 08:48:38.000 ERROR [rhodecode.config.middleware] failed to fetch settings
Traceback (most recent call last):
  File "/opt/rhodecode/store/0lg6aqzs7b4bs1x12s8i6ib5hqa285rj-python2.7-rhodecode-enterprise-ce-4.2.1/lib/python2.7/site-packages/rhodecode/config/middleware.py", line 174, in error_handler
    rc_config = SettingsModel().get_all_settings()
  File "/opt/rhodecode/store/0lg6aqzs7b4bs1x12s8i6ib5hqa285rj-python2.7-rhodecode-enterprise-ce-4.2.1/lib/python2.7/site-packages/rhodecode/model/settings.py", line 234, in get_all_settings
    return _compute()
  File "/opt/rhodecode/store/0lg6aqzs7b4bs1x12s8i6ib5hqa285rj-python2.7-rhodecode-enterprise-ce-4.2.1/lib/python2.7/site-packages/rhodecode/model/settings.py", line 217, in _compute
    for result in q
  File "/opt/rhodecode/store/0lg6aqzs7b4bs1x12s8i6ib5hqa285rj-python2.7-rhodecode-enterprise-ce-4.2.1/lib/python2.7/site-packages/rhodecode/lib/caching_query.py", line 105, in __iter__
    return Query.__iter__(self)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2441, in __iter__
    return self._execute_and_instances(context)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2454, in _execute_and_instances
    close_with_result=True)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2445, in _connection_from_session
    **kw)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 880, in connection
    execution_options=execution_options)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 885, in _connection_for_bind
    engine, execution_options)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 326, in _connection_for_bind
    conn = bind.contextual_connect()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1910, in contextual_connect
    self.pool.connect(),
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/pool.py", line 338, in connect
    return _ConnectionFairy._checkout(self)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/pool.py", line 645, in _checkout
    fairy = _ConnectionRecord.checkout(pool)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/pool.py", line 442, in checkout
    dbapi_connection = rec.get_connection()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/pool.py", line 506, in get_connection
    self.connection = self.__connect()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/pool.py", line 539, in __connect
    connection = self.__pool._creator()
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/strategies.py", line 96, in connect
    connection_invalidated=invalidated
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/strategies.py", line 90, in connect
    return dialect.connect(*cargs, **cparams)
  File "/opt/rhodecode/store/rvbznw1hks4ix1pnlfmpfwh9sqmm287d-python2.7-SQLAlchemy-0.9.9/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 377, in connect
    return self.dbapi.connect(*cargs, **cparams)
  File "/opt/rhodecode/store/70w1dh4xc8q6m8avi9d90c5qn614cbaz-python2.7-MySQL-python-1.2.5/lib/python2.7/site-packages/MySQLdb/__init__.py", line 81, in Connect
    return Connection(*args, **kwargs)
File "/opt/rhodecode/store/70w1dh4xc8q6m8avi9d90c5qn614cbaz-python2.7-MySQL-python-1.2.5/lib/python2.7/site-packages/MySQLdb/connections.py", line 193, in __init__
    super(Connection, self).__init__(*args, **kwargs2)

I don't think it's an issue with our MySQL server since the problem occurred after upgrading to Rhodecode 4.2. If I run rccontrol restart community-1 the issues goes away for a while (didn't figure out a pattern yet).

We are running:

rhodecode@vcs:~$ rccontrol status

 - NAME: community-1
 - STATUS: RUNNING
 - TYPE: Community
 - VERSION: 4.2.1
 - VCS: vcsserver-1
 - URL: http://0.0.0.0:5000

 - NAME: vcsserver-1
 - STATUS: RUNNING
 - TYPE: VCSServer
 - VERSION: 4.2.1
 - URL: http://127.0.0.1:10001

And MySQL 5.5

Marcin Kuzminski [staff] wrote:

Hi Craig,

What version are you using currently ? It's somehow known problem, and if it;s not mysql problem itself we usually fixed it by setting pool_recycle inside the ini file:
https://code.rhodecode.com/rhodecode-enterprise-ce/files/e0af06ce5559c7cdd1359f33a681ca6c73e35bae/configs/development.ini#L462

and for beaker sessions as well:

https://code.rhodecode.com/rhodecode-enterprise-ce/files/e0af06ce5559c7cdd1359f33a681ca6c73e35bae/configs/development.ini#L343

#4 Updated by Marcin Kuzminski [staff] about 3 years ago

Hi Mihai,

One more thing to check:

  • are you not having celery enabled and not running by any chance ?

Please check your .ini settings for celery settings and check if it's enabled/disabled.

#5 Updated by Mihai Nica about 3 years ago

Celery is not enabled: use_celery = false

#6 Updated by Marcin Kuzminski [staff] about 3 years ago

Mihai-

After analysing your traceback i think it's totally different error. Could you open a new ticket, we want to investigate this.

Also available in: Atom PDF