Can't reconnect until invalid transaction is rolled back

EinsteinGit commented 9 years ago
OpenTaxii server responds with ERROR to all requests following some period of inactivity - e.g. overnight. The only fix is to kill and restart the OpenTaxii server.
Using OpenTaxii with MySQL.
The error "Can't reconnect until invalid transaction is rolled back" features in the log files.
chipi commented 9 years ago
Thanks for submission!
We will start looking into it ASAP. We have not seen such behavior in our setup where unfortunately we always use PostgreSQL (native or Amazon RDS).
Few requests from our side:
Is it possible if you attach here full log?
Also sometimes, issues of this type come from how connection string is defined, so can you please share your configuration file where you have defined connection toward MySQL?
Finally, which version of OpenTAXII and MySQL you're using? Also, native install or Docker containers?
traut commented 9 years ago
@EinsteinGit there should be an SQL exception just about that error you posted. Could you please find it?
EinsteinGit commented 9 years ago
Unfortunately log file was erased on restart. I'll append log file tomorrow.
MySQL version 5.1.73 (came with yum for my version of CentOS) OpenTaxii version 0.1.2 (the one that pip installed on ~5 October) sqlalchemy version 1.0.9 MySQL-python version 1.2.5 Running within gunicorn version 19.0.3
The defaults.yml file looks as follows:

domain: "localhost:9000" support_basic_auth: yes
persistence_api: class: opentaxii.persistence.sqldb.SQLDatabaseAPI parameters: db_connection: mysql://user:pass@localhost:3306/taxii_pdb create_tables: yes
auth_api: class: opentaxii.auth.sqldb.SQLDatabaseAPI parameters: db_connection: mysql://user:pass@localhost:3306/taxii_adb create_tables: yes secret: SECRET-STRING-NEEDS-TO-BE-CHANGED
logging: opentaxii: info root: info
hooks:
EinsteinGit commented 9 years ago
Here is the log since yesterday's restart:
nohup: ignoring input
[2015-10-26 11:57:06 +0000] [25876] [INFO] Starting gunicorn 19.3.0
[2015-10-26 11:57:06 +0000] [25876] [INFO] Listening at: http://123.456.150.46:9000 (25876)
[2015-10-26 11:57:06 +0000] [25876] [INFO] Using worker: sync
[2015-10-26 11:57:06 +0000] [25881] [INFO] Booting worker with pid: 25881
{"timestamp": "2015-10-26T11:57:07.150313Z", "logger": "opentaxii.server", "api_class": "SQLDatabaseAPI", "event": "api.persistence.loaded", "level": "info"}
{"timestamp": "2015-10-26T11:57:07.169281Z", "logger": "opentaxii.server", "api_class": "SQLDatabaseAPI", "event": "api.auth.loaded", "level": "info"}
{"timestamp": "2015-10-26T11:57:07.169576Z", "logger": "opentaxii.server", "event": "taxiiserver.configured", "level": "info"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T13:51:15.312593Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T13:54:55.964867Z", "logger": "opentaxii.middleware", "event": "Status exception"}
[2015-10-26 13:56:02 +0000] [25876] [CRITICAL] WORKER TIMEOUT (pid:25881)
[2015-10-26 13:56:02 +0000] [28395] [INFO] Booting worker with pid: 28395
{"timestamp": "2015-10-26T13:56:03.047529Z", "logger": "opentaxii.server", "api_class": "SQLDatabaseAPI", "event": "api.persistence.loaded", "level": "info"}
{"timestamp": "2015-10-26T13:56:03.067674Z", "logger": "opentaxii.server", "api_class": "SQLDatabaseAPI", "event": "api.auth.loaded", "level": "info"}
{"timestamp": "2015-10-26T13:56:03.068010Z", "logger": "opentaxii.server", "event": "taxiiserver.configured", "level": "info"}
[2015-10-26 13:57:12 +0000] [25876] [CRITICAL] WORKER TIMEOUT (pid:28395)
[2015-10-26 13:57:12 +0000] [28422] [INFO] Booting worker with pid: 28422
{"timestamp": "2015-10-26T13:57:13.251257Z", "logger": "opentaxii.server", "api_class": "SQLDatabaseAPI", "event": "api.persistence.loaded", "level": "info"}
{"timestamp": "2015-10-26T13:57:13.270504Z", "logger": "opentaxii.server", "api_class": "SQLDatabaseAPI", "event": "api.auth.loaded", "level": "info"}
{"timestamp": "2015-10-26T13:57:13.270834Z", "logger": "opentaxii.server", "event": "taxiiserver.configured", "level": "info"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T13:59:14.900371Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T14:01:58.846921Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T14:02:54.583169Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "poll_alpha_cio", "logger": "opentaxii.taxii.services.poll.PollService", "message_type": "Poll_Request", "message_id": "c1929d4c-abf4-41b7-b8d3-6a8c7db175c2"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 73, in wrapper\n    return _process_with_service(service)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 142, in _process_with_service\n    response_message = service.process(request.headers, taxii_message)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/taxii/services/abstract.py\", line 76, in process\n    response_message = handler.handle_message(self, message)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/taxii/services/handlers/poll_request_handlers.py\", line 262, in handle_message\n    return PollRequest11Handler.handle_message(service, request)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/taxii/services/handlers/poll_request_handlers.py\", line 77, in handle_message\n    request.message_id)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/taxii/services/handlers/poll_request_handlers.py\", line 33, in retrieve_subscription\n    in_response_to=in_response_to, status_details=details)\nStatusMessageException: The subscription requested was not found", "level": "warning", "timestamp": "2015-10-26T14:02:54.592674Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T14:03:21.233660Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "925834c6-db4f-41fe-8d8d-39b109d8278c"}
Exception on /services/discovery_alpha_cio [POST]
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py", line 60, in wrapper
    request.headers.get(HTTP_AUTHORIZATION)
  File "/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py", line 116, in _authenticate
    account = server.auth.get_account(token)
  File "/usr/local/lib/python2.7/site-packages/opentaxii/auth/manager.py", line 34, in get_account
    return self.api.get_account(token)
  File "/usr/local/lib/python2.7/site-packages/opentaxii/auth/sqldb/api.py", line 64, in get_account
    account_id = self._get_account_id(token)
  File "/usr/local/lib/python2.7/site-packages/opentaxii/auth/sqldb/api.py", line 96, in _get_account_id
    payload = jwt.decode(token, self.secret)
  File "/usr/local/lib/python2.7/site-packages/jwt/api_jwt.py", line 61, in decode
    payload, signing_input, header, signature = self._load(jwt)
  File "/usr/local/lib/python2.7/site-packages/jwt/api_jws.py", line 135, in _load
    signing_input, crypto_segment = jwt.rsplit(b'.', 1)
AttributeError: 'NoneType' object has no attribute 'rsplit'
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1817, in wsgi_app\n    response = self.full_dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1477, in full_dispatch_request\n    rv = self.handle_user_exception(e)\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1381, in handle_user_exception\n    reraise(exc_type, exc_value, tb)\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 60, in wrapper\n    request.headers.get(HTTP_AUTHORIZATION)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 116, in _authenticate\n    account = server.auth.get_account(token)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/auth/manager.py\", line 34, in get_account\n    return self.api.get_account(token)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/auth/sqldb/api.py\", line 64, in get_account\n    account_id = self._get_account_id(token)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/auth/sqldb/api.py\", line 96, in _get_account_id\n    payload = jwt.decode(token, self.secret)\n  File \"/usr/local/lib/python2.7/site-packages/jwt/api_jwt.py\", line 61, in decode\n    payload, signing_input, header, signature = self._load(jwt)\n  File \"/usr/local/lib/python2.7/site-packages/jwt/api_jws.py\", line 135, in _load\n    signing_input, crypto_segment = jwt.rsplit(b'.', 1)\nAttributeError: 'NoneType' object has no attribute 'rsplit'", "level": "error", "timestamp": "2015-10-26T14:03:56.189999Z", "logger": "opentaxii.middleware", "event": "Internal error"}
{"level": "info", "timestamp": "2015-10-26T14:04:06.513438Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "ffb62e02-963c-4257-a680-1dfbd4b6dcff"}
{"level": "info", "timestamp": "2015-10-26T14:05:34.264398Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:38d4cace-d38a-4721-9fad-4defc6696b56"}
{"level": "info", "timestamp": "2015-10-26T14:06:24.507102Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:641d9c8d-caef-4285-9b29-1e83310daffd"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T14:06:26.626463Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T14:29:09.751385Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:bc7264d4-a411-4c68-a87e-7b5d9c31104d"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T14:29:13.038397Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T14:34:07.386591Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:9ffee67e-7bb5-48c9-8753-a45b9fc01de3"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T14:34:09.794863Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T14:42:08.958999Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:20e74ce6-0f86-4b24-bc70-ce05d01d053c"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T14:42:11.845267Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T15:19:49.573656Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:64350c1a-43ac-415c-80e5-543623350d19"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T15:19:52.113673Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T15:31:03.402882Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:e3c5bd58-1ab4-4f34-8b06-671aa1bb3b57"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T15:31:05.720662Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T15:36:50.561155Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:309a8824-95d7-4a05-a718-c8ac22ebcfce"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T15:36:52.681084Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T15:39:55.126219Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:f79122b1-164b-4caf-adfc-a5b8aee3d077"}
{"level": "info", "timestamp": "2015-10-26T15:47:46.932714Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:e92ed908-269c-45ee-a0c9-670e07b0ef00"}
{"level": "info", "timestamp": "2015-10-26T15:48:30.244081Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:d3602f13-2df4-4e75-9df8-f290e49e1a51"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T15:48:32.602726Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T15:49:02.800090Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:4c4de1f5-0d14-4c5f-aaa8-c4fc8a9485ce"}
{"level": "info", "timestamp": "2015-10-26T15:50:08.393728Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:9ddfeba8-1500-482a-b24c-986d2e6caa0b"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T15:50:10.566970Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T15:51:33.064336Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:af1bcf14-5aad-4482-80ef-b0f0d3d4b8a5"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T15:51:35.473086Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T15:52:05.361999Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:524d8bd0-be7c-46c5-b554-b6dd3ad09462"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T15:52:08.595490Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T15:56:47.493839Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:eb611925-d93d-41d0-afe0-c6b0a4bfd217"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T15:56:50.409629Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T16:03:55.646788Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T16:05:35.940515Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "inbox_alpha_cio", "logger": "opentaxii.taxii.services.inbox.InboxService", "message_type": "Inbox_Message", "message_id": "d29ca093-22b0-47f7-8d77-e47855b3f13d"}
/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py:450: Warning: Out of range value for column 'timestamp_label' at row 1
  cursor.execute(statement, parameters)
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T16:09:47.507728Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T16:10:53.086501Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "inbox_beta_cio", "logger": "opentaxii.taxii.services.inbox.InboxService", "message_type": "Inbox_Message", "message_id": "ea2f3ef0-dd3e-41cc-96f0-23e3c9b06472"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T16:16:29.243985Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T16:18:22.582247Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T16:25:00.500737Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T17:24:58.245771Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T17:36:02.256342Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T17:38:34.809832Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:23612784-71de-4f8b-b042-e5f8a7c40162"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T17:38:38.252259Z", "logger": "opentaxii.middleware", "event": "Status exception"}
{"level": "info", "timestamp": "2015-10-26T17:56:21.595252Z", "event": "Processing message", "message_version": "urn:taxii.mitre.org:message:xml:1.1", "service_id": "discovery_alpha_cio", "logger": "opentaxii.taxii.services.discovery.DiscoveryService", "message_type": "Discovery_Request", "message_id": "urn:uuid:9b53a72b-02b7-4e0a-8cb8-6fd905381ea1"}
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 67, in wrapper\n    raise UnauthorizedException()\nUnauthorizedException: UNAUTHORIZED", "level": "warning", "timestamp": "2015-10-26T17:56:25.947815Z", "logger": "opentaxii.middleware", "event": "Status exception"}
Exception on /services/discovery_alpha_finance [POST]
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py", line 63, in wrapper
    for service in server.get_services():
  File "/usr/local/lib/python2.7/site-packages/opentaxii/server.py", line 104, in get_services
    service_entities = self.persistence.get_services()
  File "/usr/local/lib/python2.7/site-packages/opentaxii/persistence/manager.py", line 68, in get_services
    return self.api.get_services()
  File "/usr/local/lib/python2.7/site-packages/opentaxii/persistence/sqldb/api.py", line 60, in get_services
    services = self.Service.query.all()
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2423, in all
    return list(self)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2571, in __iter__
    return self._execute_and_instances(context)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2586, in _execute_and_instances
    result = conn.execute(querycontext.statement, self._params)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
    return meth(self, multiparams, params)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
    compiled_sql, distilled_params
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
    context)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1341, in _handle_dbapi_exception
    exc_info
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
    context)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
    cursor.execute(statement, parameters)
  File "/usr/local/lib/python2.7/site-packages/MySQLdb/cursors.py", line 205, in execute
    self.errorhandler(self, exc, value)
  File "/usr/local/lib/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
    raise errorclass, errorvalue
OperationalError: (_mysql_exceptions.OperationalError) (2006, 'MySQL server has gone away') [SQL: u'SELECT services.date_created AS services_date_created, services.date_updated AS services_date_updated, services.id AS services_id, services.type AS services_type, services._properties AS services__properties \nFROM services']
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1817, in wsgi_app\n    response = self.full_dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1477, in full_dispatch_request\n    rv = self.handle_user_exception(e)\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1381, in handle_user_exception\n    reraise(exc_type, exc_value, tb)\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 63, in wrapper\n    for service in server.get_services():\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/server.py\", line 104, in get_services\n    service_entities = self.persistence.get_services()\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/persistence/manager.py\", line 68, in get_services\n    return self.api.get_services()\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/persistence/sqldb/api.py\", line 60, in get_services\n    services = self.Service.query.all()\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py\", line 2423, in all\n    return list(self)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py\", line 2571, in __iter__\n    return self._execute_and_instances(context)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py\", line 2586, in _execute_and_instances\n    result = conn.execute(querycontext.statement, self._params)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 914, in execute\n    return meth(self, multiparams, params)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py\", line 323, in _execute_on_connection\n    return connection._execute_clauseelement(self, multiparams, params)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1010, in _execute_clauseelement\n    compiled_sql, distilled_params\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1146, in _execute_context\n    context)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1341, in _handle_dbapi_exception\n    exc_info\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py\", line 199, in raise_from_cause\n    reraise(type(exception), exception, tb=exc_tb)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1139, in _execute_context\n    context)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py\", line 450, in do_execute\n    cursor.execute(statement, parameters)\n  File \"/usr/local/lib/python2.7/site-packages/MySQLdb/cursors.py\", line 205, in execute\n    self.errorhandler(self, exc, value)\n  File \"/usr/local/lib/python2.7/site-packages/MySQLdb/connections.py\", line 36, in defaulterrorhandler\n    raise errorclass, errorvalue\nOperationalError: (_mysql_exceptions.OperationalError) (2006, 'MySQL server has gone away') [SQL: u'SELECT services.date_created AS services_date_created, services.date_updated AS services_date_updated, services.id AS services_id, services.type AS services_type, services._properties AS services__properties \\nFROM services']", "level": "error", "timestamp": "2015-10-27T09:14:19.653391Z", "logger": "opentaxii.middleware", "event": "Internal error"}
Exception on /services/discovery_alpha_finance [POST]
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1817, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1477, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1381, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1475, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python2.7/site-packages/flask/app.py", line 1461, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py", line 63, in wrapper
    for service in server.get_services():
  File "/usr/local/lib/python2.7/site-packages/opentaxii/server.py", line 104, in get_services
    service_entities = self.persistence.get_services()
  File "/usr/local/lib/python2.7/site-packages/opentaxii/persistence/manager.py", line 68, in get_services
    return self.api.get_services()
  File "/usr/local/lib/python2.7/site-packages/opentaxii/persistence/sqldb/api.py", line 60, in get_services
    services = self.Service.query.all()
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2423, in all
    return list(self)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2571, in __iter__
    return self._execute_and_instances(context)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2586, in _execute_and_instances
    result = conn.execute(querycontext.statement, self._params)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
    return meth(self, multiparams, params)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
    compiled_sql, distilled_params
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1078, in _execute_context
    None, None)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1341, in _handle_dbapi_exception
    exc_info
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb)
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1071, in _execute_context
    conn = self._revalidate_connection()
  File "/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 391, in _revalidate_connection
    "Can't reconnect until invalid "
StatementError: (sqlalchemy.exc.InvalidRequestError) Can't reconnect until invalid transaction is rolled back [SQL: u'SELECT services.date_created AS services_date_created, services.date_updated AS services_date_updated, services.id AS services_id, services.type AS services_type, services._properties AS services__properties \nFROM services'] [parameters: [immutabledict({})]]
{"exception": "Traceback (most recent call last):\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1817, in wsgi_app\n    response = self.full_dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1477, in full_dispatch_request\n    rv = self.handle_user_exception(e)\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1381, in handle_user_exception\n    reraise(exc_type, exc_value, tb)\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1475, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/usr/local/lib/python2.7/site-packages/flask/app.py\", line 1461, in dispatch_request\n    return self.view_functions[rule.endpoint](**req.view_args)\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/middleware.py\", line 63, in wrapper\n    for service in server.get_services():\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/server.py\", line 104, in get_services\n    service_entities = self.persistence.get_services()\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/persistence/manager.py\", line 68, in get_services\n    return self.api.get_services()\n  File \"/usr/local/lib/python2.7/site-packages/opentaxii/persistence/sqldb/api.py\", line 60, in get_services\n    services = self.Service.query.all()\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py\", line 2423, in all\n    return list(self)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py\", line 2571, in __iter__\n    return self._execute_and_instances(context)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py\", line 2586, in _execute_and_instances\n    result = conn.execute(querycontext.statement, self._params)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 914, in execute\n    return meth(self, multiparams, params)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py\", line 323, in _execute_on_connection\n    return connection._execute_clauseelement(self, multiparams, params)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1010, in _execute_clauseelement\n    compiled_sql, distilled_params\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1078, in _execute_context\n    None, None)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1341, in _handle_dbapi_exception\n    exc_info\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py\", line 199, in raise_from_cause\n    reraise(type(exception), exception, tb=exc_tb)\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1071, in _execute_context\n    conn = self._revalidate_connection()\n  File \"/usr/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py\", line 391, in _revalidate_connection\n    \"Can't reconnect until invalid \"\nStatementError: (sqlalchemy.exc.InvalidRequestError) Can't reconnect until invalid transaction is rolled back [SQL: u'SELECT services.date_created AS services_date_created, services.date_updated AS services_date_updated, services.id AS services_id, services.type AS services_type, services._properties AS services__properties \\nFROM services'] [parameters: [immutabledict({})]]", "level": "error", "timestamp": "2015-10-27T09:19:11.776222Z", "logger": "opentaxii.middleware", "event": "Internal error"}
traut commented 9 years ago
@EinsteinGit a few things I noticed:
do not change opentaxii/defaults.yaml file shipped with OpenTAXII, instead supply your own configuration file
for some reason your workers are timing out: [2015-10-26 13:57:12 +0000] [25876] [CRITICAL] WORKER TIMEOUT (pid:28395). Any idea what is happening? Do you have a good connectivity to your MySQL DB server?
there are many UnauthorizedException exceptions in the log you provided. It seems like you've configured services with authentication_required: yes but now you're sending requests without proper JWT token.
The server died after this exception: OperationalError: (_mysql_exceptions.OperationalError) (2006, 'MySQL server has gone away') [SQL: u'SELECT services.date_created AS services_date_created, services.date_updated AS services_date_updated, services.id AS services_id, services.type AS services_type, services._properties AS services__properties \nFROM services'] . It seems like OpenTAXII lost connection to MySQL DB server and could not carry on. Again, maybe a connectivity to your DB server is an issue.
EinsteinGit commented 9 years ago
Thanks for looking at the logs.
I don't know why the workers timed out at the beginning. But they seem to have restarted themselves since then.
the UnauthorizedException exceptions were expected. We were trying to send requests using the java-taxi API and we were doing something wrong with the http client, so it was not sending the authentication credentials.
I don't think there is an underlying connectivity issue. I am running the db on the same machine as the opentaxii server, although it is going out to a proxy and coming back in.
there are no logs between 17:56 when the last "successful" request was sent and the morning when I tried another request and I got the 2006, 'MySQL server has gone away' error. Upon restarting the taxii server, the issue was gone. So, network connectivity is not the problem.
Could it be MySQL has a session timeout?
I switched to a postgreSQL db yesterday and that did not have the problem. It is still working fine.
traut commented 9 years ago
@EinsteinGit thanks for the details!
Maybe it is indeed MySQL session issue, I'll try to verify that. We're using OpenTAXII mostly with PostgreSQL and there were no issues like that reported.
EinsteinGit commented 9 years ago
According to MySQL docs, the server variable wait_timeout - "the number of seconds the server waits for activity on a noninteractive connection before closing it" - has a default value of 8 hrs which explains why MySQL was not reachable after overnight inactivity. I set its value to a larger interval in /etc/my.cnf , and it is now working fine after a night of inactivity.
eclecticiq / OpenTAXII

Can't reconnect until invalid transaction is rolled back #38

The defaults.yml file looks as follows:
