After Dockerimage rebuild Syncserver is no longer sync

[misterhsp]

I just rebuilt my docker image from Syncserver. But I have to notice that it doesn't sync anymore on my fxa-selfhosting after the rebuild. Anyone have an idea where this could be stuck? It's probably related to the recent commits, I think.

Start I do the image starts like this.

docker run --detach --rm --name sync
--env "SYNCSERVER_PUBLIC_URL=https://fxa.localhorst.home:5000"
--env "SYNCSERVER_SECRET=xxxxxxxxxxxxxxxxxxxx"
--env "SYNCSERVER_SQLURI=pymysql://fxa:[email protected]/syncserver"
--env "SYNCSERVER_IDENTITY_PROVIDER=https://fxa.localhorst.home:3030"
--env "SYNCSERVER_BROWSERID_VERIFIER=https://fxa.localhorst.home:5050/v2"
--env "SYNCSERVER_BATCH_UPLOAD_ENABLED=true"
--env "SYNCSERVER_ALLOW_NEW_USERS=true"
--env "SYNCSERVER_FORCE_WSGI_ENVIRON=true"
--env "REQUESTS_CA_BUNDLE=/etc/ssl/certs/ca-certificates.crt"
--add-host="hsp2.localhorst.home:192.168.0.2"
--add-host="fxa.localhorst.home:192.168.0.17"
syncserver:latest

Thanks in advance

[misterhsp]

Nobody has any ideas?

...

[TheForcer]

I seem to have the same issue using Docker, Sync does not work anymore. According to the Docker logs maybe the database structure of an existing installation is not compatible with the recent commits?

OperationalError: (sqlite3.OperationalError) no such column: keys_changed_at
[SQL: select
    uid, generation, client_state, created_at, replaced_at,
    keys_changed_at, node
from
    users
where
    email = ?
and
    service = ?
order by
    created_at desc, uid desc
limit
    20
]

[jrconlin]

Sorry, a bunch of us were unavailable last week.

The problem is that there was a change to the database and the migration didn't fire for docker.
#193 (comment) has the fix.

[TheForcer]

No problem, thanks for providing the hint. My instance is running again :)

[misterhsp]

I use mariaDB, can this be implemented in the same way? The fix says something about sqlite.

Thanks...

[alexfornuto]

I am also using mariadb, and have run the commands to update linked above to ADD keys_changed and ADD node. What else is needed to get my sync server running again?

[rfk]

I use mariaDB, can this be implemented in the same way? The fix says something about sqlite.

Yes, the linked queries should work fine on mariaDB as well as sqlite.

[alexfornuto]

Well I added the columns and still got the keys_changed error.

[eric-pierce]

I've added the columns and the syncserver is functioning again, but I still periodically get a related error so I think that adding the columns alone doesn't appear to resolve this entirely.

Error below, it may be related to me changing the database password. I'm running via docker so I did try deleting the image outright and re-downloading, but the issue persists:

`ERROR:mozsvc:Uncaught exception while processing request:
GET https://REMOVED/token/1.0/sync/1.5
Uncaught exception:
File "/usr/local/lib/python2.7/site-packages/mozsvc/tweens.py", line 59, in log_uncaught_exceptions_tween
return handler(request)
File "/usr/local/lib/python2.7/site-packages/mozsvc/tweens.py", line 26, in catch_backend_errors_tween
return handler(request)
File "/usr/local/lib/python2.7/site-packages/pyramid/tweens.py", line 21, in excview_tween
response = handler(request)
File "/usr/local/lib/python2.7/site-packages/pyramid/router.py", line 163, in handle_request
response = view_callable(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 596, in call
return view(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 329, in attr_view
return view(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 305, in predicate_wrapper
return view(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 355, in rendered_view
result = view(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 501, in requestonly_view
response = view(request)
File "/usr/local/lib/python2.7/site-packages/cornice/service.py", line 514, in wrapper
response = view(request)
File "/usr/local/lib/python2.7/site-packages/tokenserver/views.py", line 345, in return_token
user = backend.get_user(service, email)
File "/app/syncserver/staticnode.py", line 135, in get_user
res = self._engine.execute(_GET_USER_RECORDS, **params)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 2166, in execute
return connection.execute(statement, *multiparams, **params)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 988, in execute
return meth(self, multiparams, params)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 287, in _execute_on_connection
return connection._execute_clauseelement(self, multiparams, params)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1107, in _execute_clauseelement
distilled_params,
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
e, statement, parameters, cursor, context
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1466, in _handle_dbapi_exception
util.raise_from_cause(sqlalchemy_exception, exc_info)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 383, in raise_from_cause
reraise(type(exception), exception, tb=exc_tb, cause=cause)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
cursor, statement, parameters, context
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
cursor.execute(statement, parameters)
File "/usr/local/lib/python2.7/site-packages/pymysql/cursors.py", line 170, in execute
result = self._query(query)
File "/usr/local/lib/python2.7/site-packages/pymysql/cursors.py", line 328, in _query
conn.query(q)
File "/usr/local/lib/python2.7/site-packages/pymysql/connections.py", line 516, in query
self._execute_command(COMMAND.COM_QUERY, sql)
File "/usr/local/lib/python2.7/site-packages/pymysql/connections.py", line 771, in _execute_command
self._write_bytes(packet)
File "/usr/local/lib/python2.7/site-packages/pymysql/connections.py", line 718, in _write_bytes
"MySQL server has gone away (%r)" % (e,))
<class 'sqlalchemy.exc.OperationalError'>
OperationalError('(pymysql.err.OperationalError) (2006, "MySQL server has gone away (error(104, 'Connection reset by peer'))")',)

[2020-02-12 20:36:06 +0000] [11] [ERROR] Error handling request /token/1.0/sync/1.5
Traceback (most recent call last):
File "/usr/local/lib/python2.7/site-packages/gunicorn/workers/sync.py", line 135, in handle
self.handle_request(listener, req, client, addr)
File "/usr/local/lib/python2.7/site-packages/gunicorn/workers/sync.py", line 176, in handle_request
respiter = self.wsgi(environ, resp.start_response)
File "/usr/local/lib/python2.7/site-packages/pyramid/router.py", line 242, in call
response = self.invoke_subrequest(request, use_tweens=True)
File "/usr/local/lib/python2.7/site-packages/pyramid/router.py", line 217, in invoke_subrequest
response = handle_request(request)
File "/usr/local/lib/python2.7/site-packages/tokenserver/tweens.py", line 15, in set_x_timestamp_header_tween
response = handler(request)
File "/usr/local/lib/python2.7/site-packages/syncstorage/tweens.py", line 123, in convert_non_json_responses_tween
response = handler(request)
File "/usr/local/lib/python2.7/site-packages/syncstorage/tweens.py", line 99, in convert_cornice_errors_to_respcodes_tween
response = handler(request)
File "/usr/local/lib/python2.7/site-packages/syncstorage/tweens.py", line 53, in set_default_accept_header_tween
return handler(request)
File "/usr/local/lib/python2.7/site-packages/syncstorage/tweens.py", line 30, in set_x_timestamp_header_tween
response = handler(request)
File "/usr/local/lib/python2.7/site-packages/mozsvc/tweens.py", line 94, in fuzz_backoff_headers_tween
response = handler(request)
File "/usr/local/lib/python2.7/site-packages/mozsvc/tweens.py", line 59, in log_uncaught_exceptions_tween
return handler(request)
File "/usr/local/lib/python2.7/site-packages/mozsvc/tweens.py", line 26, in catch_backend_errors_tween
return handler(request)
File "/usr/local/lib/python2.7/site-packages/pyramid/tweens.py", line 21, in excview_tween
response = handler(request)
File "/usr/local/lib/python2.7/site-packages/pyramid/router.py", line 163, in handle_request
response = view_callable(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 596, in call
return view(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 329, in attr_view
return view(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 305, in predicate_wrapper
return view(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 355, in rendered_view
result = view(context, request)
File "/usr/local/lib/python2.7/site-packages/pyramid/config/views.py", line 501, in requestonly_view
response = view(request)
File "/usr/local/lib/python2.7/site-packages/cornice/service.py", line 514, in wrapper
response = view(request)
File "/usr/local/lib/python2.7/site-packages/tokenserver/views.py", line 345, in return_token
user = backend.get_user(service, email)
File "/app/syncserver/staticnode.py", line 135, in get_user
res = self._engine.execute(_GET_USER_RECORDS, **params)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 2166, in execute
return connection.execute(statement, *multiparams, **params)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 988, in execute
return meth(self, multiparams, params)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 287, in _execute_on_connection
return connection._execute_clauseelement(self, multiparams, params)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1107, in _execute_clauseelement
distilled_params,
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
e, statement, parameters, cursor, context
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1466, in _handle_dbapi_exception
util.raise_from_cause(sqlalchemy_exception, exc_info)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 383, in raise_from_cause
reraise(type(exception), exception, tb=exc_tb, cause=cause)
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
cursor, statement, parameters, context
File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
cursor.execute(statement, parameters)
File "/usr/local/lib/python2.7/site-packages/pymysql/cursors.py", line 170, in execute
result = self._query(query)
File "/usr/local/lib/python2.7/site-packages/pymysql/cursors.py", line 328, in _query
conn.query(q)
File "/usr/local/lib/python2.7/site-packages/pymysql/connections.py", line 516, in query
self._execute_command(COMMAND.COM_QUERY, sql)
File "/usr/local/lib/python2.7/site-packages/pymysql/connections.py", line 771, in _execute_command
self._write_bytes(packet)
File "/usr/local/lib/python2.7/site-packages/pymysql/connections.py", line 718, in _write_bytes
"MySQL server has gone away (%r)" % (e,))
OperationalError: (pymysql.err.OperationalError) (2006, "MySQL server has gone away (error(104, 'Connection reset by peer'))")
[SQL: select
uid, generation, client_state, created_at, replaced_at,
keys_changed_at, node
from
users
where
email = %(email)s
and
service = %(service)s
order by
created_at desc, uid desc
limit
20
]`

[rfk]

OperationalError('(pymysql.err.OperationalError) (2006, "MySQL server has gone away (error(104, 'Connection reset by peer'))")',)

I believe this is the connection between your app and MySQL timing out; you could try upping the connection timeout on the MySQL side and see if that helps.

I'm surprised the app doesn't recover from this automatically by taking a fresh connection, but perhaps we don't encounter these under load in production so it's never come up.

[eric-pierce]

@rfk thanks I took a look and my wait_timeout was set to 600, I set it to the default value for mariadb of 28800. I'll report back if that appears to have resolved it.

[okin]

OperationalError('(pymysql.err.OperationalError) (2006, "MySQL server has gone away (error(104, 'Connection reset by peer'))")',)

I believe this is the connection between your app and MySQL timing out; you could try upping the connection timeout on the MySQL side and see if that helps.

I'm surprised the app doesn't recover from this automatically by taking a fresh connection, but perhaps we don't encounter these under load in production so it's never come up.

With sqlalchemy you have to specify that you want to have connections recycled after a specific period of time through the connection_pool_recycle parameter during engine creation.

[alexfornuto]

Sorry, but how can I turn that information into a working sync server?