synapse.log

2018-11-05 17:22:01,360 - root - 212 - WARNING - None- ***** STARTING SERVER *****
2018-11-05 17:22:01,369 - synapse.util.versionstring - 82 - INFO - None- Failed to check for git repository: [Errno 2] No such file or directory
2018-11-05 17:22:01,370 - root - 215 - WARNING - None- Server /usr/local/lib/python2.7/site-packages/synapse/app/homeserver.py version 0.33.8
2018-11-05 17:22:01,370 - root - 217 - INFO - None- Server hostname: thewordnerd.info
2018-11-05 17:22:01,371 - synapse.python_dependencies - 143 - INFO - None- Using 'saml2' version '4.6.3' from '/usr/local/lib/python2.7/site-packages/saml2/__init__.pyc' to satisfy 'pysaml2>=3.0.0'
2018-11-05 17:22:01,371 - synapse.python_dependencies - 143 - INFO - None- Using 'frozendict' version None from '/usr/local/lib/python2.7/site-packages/frozendict/__init__.pyc' to satisfy 'frozendict>=1'
2018-11-05 17:22:01,371 - synapse.python_dependencies - 143 - INFO - None- Using 'six' version '1.11.0' from '/usr/local/lib/python2.7/site-packages/six.pyc' to satisfy 'six>=1.10'
2018-11-05 17:22:01,371 - synapse.python_dependencies - 143 - INFO - None- Using 'canonicaljson' version '1.1.4' from '/usr/local/lib/python2.7/site-packages/canonicaljson.pyc' to satisfy 'canonicaljson>=1.1.3'
2018-11-05 17:22:01,371 - synapse.python_dependencies - 143 - INFO - None- Using 'psutil' version '5.4.8' from '/usr/local/lib/python2.7/site-packages/psutil/__init__.pyc' to satisfy 'psutil>=2.0.0'
2018-11-05 17:22:01,371 - synapse.python_dependencies - 143 - INFO - None- Using 'bcrypt' version u'3.1.4' from '/usr/local/lib/python2.7/site-packages/bcrypt/__init__.pyc' to satisfy 'bcrypt>=3.1.0'
2018-11-05 17:22:01,371 - synapse.python_dependencies - 143 - INFO - None- Using 'pyasn1' version '0.4.4' from '/usr/local/lib/python2.7/site-packages/pyasn1/__init__.pyc' to satisfy 'pyasn1>=0.1.9'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'pymacaroons' version '0.9.0' from '/usr/local/lib/python2.7/site-packages/pymacaroons/__init__.pyc' to satisfy 'pymacaroons-pynacl>=0.9.3'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'signedjson' version '1.0.0' from '/usr/local/lib/python2.7/site-packages/signedjson/__init__.pyc' to satisfy 'signedjson>=1.0.0'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'yaml' version '3.13' from '/usr/local/lib/python2.7/site-packages/yaml/__init__.pyc' to satisfy 'pyyaml>=3.11'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'PIL' version '5.3.0' from '/usr/local/lib/python2.7/site-packages/PIL/__init__.pyc' to satisfy 'pillow>=3.1.2'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'attr' version '18.2.0' from '/usr/local/lib/python2.7/site-packages/attr/__init__.pyc' to satisfy 'attrs>=16.0.0'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'service_identity' version '17.0.0' from '/usr/local/lib/python2.7/site-packages/service_identity/__init__.pyc' to satisfy 'service_identity>=16.0.0'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'pyasn1_modules' version '0.2.2' from '/usr/local/lib/python2.7/site-packages/pyasn1_modules/__init__.pyc' to satisfy 'pyasn1-modules>=0.0.7'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'msgpack' version None from '/usr/local/lib/python2.7/site-packages/msgpack/__init__.pyc' to satisfy 'msgpack-python>=0.4.2'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'prometheus_client' version None from '/usr/local/lib/python2.7/site-packages/prometheus_client/__init__.pyc' to satisfy 'prometheus_client>=0.0.18,<0.4.0'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'unpaddedbase64' version '1.1.0' from '/usr/local/lib/python2.7/site-packages/unpaddedbase64.pyc' to satisfy 'unpaddedbase64>=1.1.0'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'nacl' version '1.3.0' from '/usr/local/lib/python2.7/site-packages/nacl/__init__.pyc' to satisfy 'pynacl>=1.2.1'
2018-11-05 17:22:01,372 - synapse.python_dependencies - 143 - INFO - None- Using 'nacl.bindings' version '1.3.0' from '/usr/local/lib/python2.7/site-packages/nacl/__init__.pyc' to satisfy 'pynacl>=1.2.1'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'phonenumbers' version '8.9.16' from '/usr/local/lib/python2.7/site-packages/phonenumbers/__init__.pyc' to satisfy 'phonenumbers>=8.2.0'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'daemonize' version '2.4.7' from '/usr/local/lib/python2.7/site-packages/daemonize.pyc' to satisfy 'daemonize>=2.3.1'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'netaddr' version '0.7.19' from '/usr/local/lib/python2.7/site-packages/netaddr/__init__.pyc' to satisfy 'netaddr>=0.7.18'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'jsonschema' version '2.6.0' from '/usr/local/lib/python2.7/site-packages/jsonschema/__init__.pyc' to satisfy 'jsonschema>=2.5.1'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'treq' version '18.6.0' from '/usr/local/lib/python2.7/site-packages/treq/__init__.pyc' to satisfy 'treq>=15.1'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'twisted' version '18.9.0' from '/usr/local/lib/python2.7/site-packages/twisted/__init__.pyc' to satisfy 'Twisted>=17.1.0'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'OpenSSL' version '18.0.0' from '/usr/local/lib/python2.7/site-packages/OpenSSL/__init__.pyc' to satisfy 'pyopenssl>=16.0.0'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'pydenticon' version None from '/usr/local/lib/python2.7/site-packages/pydenticon/__init__.pyc' to satisfy 'pydenticon>=0.2'
2018-11-05 17:22:01,373 - synapse.python_dependencies - 143 - INFO - None- Using 'sortedcontainers' version '2.0.5' from '/usr/local/lib/python2.7/site-packages/sortedcontainers/__init__.pyc' to satisfy 'sortedcontainers>=1.4.4'
2018-11-05 17:22:01,388 - synapse.util.versionstring - 82 - INFO - None- Failed to check for git repository: [Errno 2] No such file or directory
2018-11-05 17:22:01,389 - synapse.app.homeserver - 363 - INFO - None- Preparing database: psycopg2...
2018-11-05 17:22:01,399 - synapse.storage.prepare_database - 223 - INFO - None- Upgrading schema to v51
2018-11-05 17:22:01,402 - synapse.app.homeserver - 381 - INFO - None- Database prepared in psycopg2.
2018-11-05 17:22:01,403 - synapse.server - 207 - INFO - None- Setting up.
2018-11-05 17:22:01,565 - synapse.storage.event_push_actions - 471 - INFO - None- Searching for stream ordering 1 month ago
2018-11-05 17:22:01,576 - synapse.storage.event_push_actions - 477 - INFO - None- Found stream ordering 1 month ago: it's 1603661
2018-11-05 17:22:01,576 - synapse.storage.event_push_actions - 479 - INFO - None- Searching for stream ordering 1 day ago
2018-11-05 17:22:01,583 - synapse.storage.event_push_actions - 485 - INFO - None- Found stream ordering 1 day ago: it's 1693359
2018-11-05 17:22:01,667 - synapse.server - 211 - INFO - None- Finished setting up.
2018-11-05 17:22:01,669 - synapse.handlers.auth - 80 - INFO - None- Extra password_providers: []
2018-11-05 17:22:01,671 - synapse.federation.federation_server - 777 - INFO - None- Registering federation query handler for 'profile'
2018-11-05 17:22:01,671 - synapse.push.pusher - 43 - INFO - None- email enable notifs: False
2018-11-05 17:22:01,672 - synapse.federation.federation_server - 777 - INFO - None- Registering federation query handler for 'directory'
2018-11-05 17:22:01,684 - synapse.federation.federation_server - 757 - INFO - None- Registering federation EDU handler for 'm.presence'
2018-11-05 17:22:01,684 - synapse.federation.federation_server - 757 - INFO - None- Registering federation EDU handler for 'm.presence_invite'
2018-11-05 17:22:01,684 - synapse.federation.federation_server - 757 - INFO - None- Registering federation EDU handler for 'm.presence_accept'
2018-11-05 17:22:01,684 - synapse.federation.federation_server - 757 - INFO - None- Registering federation EDU handler for 'm.presence_deny'
2018-11-05 17:22:01,686 - synapse.federation.federation_server - 757 - INFO - None- Registering federation EDU handler for 'm.typing'
2018-11-05 17:22:01,686 - synapse.federation.federation_server - 757 - INFO - None- Registering federation EDU handler for 'm.device_list_update'
2018-11-05 17:22:01,686 - synapse.federation.federation_server - 777 - INFO - None- Registering federation query handler for 'user_devices'
2018-11-05 17:22:01,689 - synapse.federation.federation_server - 757 - INFO - None- Registering federation EDU handler for 'm.receipt'
2018-11-05 17:22:01,690 - synapse.federation.federation_server - 777 - INFO - None- Registering federation query handler for 'client_keys'
2018-11-05 17:22:01,690 - synapse.federation.federation_server - 757 - INFO - None- Registering federation EDU handler for 'm.direct_to_device'
2018-11-05 17:22:01,709 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eef43990> to path /_matrix/client/r0
2018-11-05 17:22:01,709 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching FilePath('/usr/local/lib/python2.7/site-packages/synapse/static') to path /_matrix/static
2018-11-05 17:22:01,709 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eef43990> to path /_matrix/client/versions
2018-11-05 17:22:01,709 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eef43990> to path /_matrix/client/unstable
2018-11-05 17:22:01,710 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.media.v1.media_repository.MediaRepositoryResource instance at 0x7fb1eef2a8c0> to path /_matrix/media/v1
2018-11-05 17:22:01,710 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eef43990> to path /_matrix/client/api/v1
2018-11-05 17:22:01,710 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.media.v0.content_repository.ContentRepoResource instance at 0x7fb1eef2add0> to path /_matrix/content
2018-11-05 17:22:01,710 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.key.v2.KeyApiV2Resource instance at 0x7fb1eeed3ea8> to path /_matrix/key/v2
2018-11-05 17:22:01,710 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eef43990> to path /_matrix/client/v2_alpha
2018-11-05 17:22:01,710 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.key.v1.server_key_resource.LocalKey instance at 0x7fb1eef2ae60> to path /_matrix/key/v1
2018-11-05 17:22:01,710 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.media.v1.media_repository.MediaRepositoryResource instance at 0x7fb1eef2a8c0> to path /_matrix/media/r0
2018-11-05 17:22:01,710 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.federation.transport.server.TransportLayerServer object at 0x7fb1eef43a50> to path /_matrix/federation/v1
2018-11-05 17:22:01,711 - twisted - 243 - INFO - None- SynapseSite (TLS) starting on 8448
2018-11-05 17:22:01,712 - synapse.app.homeserver - 175 - INFO - None- Synapse now listening on port 8448
2018-11-05 17:22:01,728 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eee4b510> to path /_matrix/client/r0
2018-11-05 17:22:01,728 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching FilePath('/usr/local/lib/python2.7/site-packages/synapse/static') to path /_matrix/static
2018-11-05 17:22:01,728 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eee4b510> to path /_matrix/client/versions
2018-11-05 17:22:01,729 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eee4b510> to path /_matrix/client/unstable
2018-11-05 17:22:01,729 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.media.v1.media_repository.MediaRepositoryResource instance at 0x7fb1eef2a8c0> to path /_matrix/media/v1
2018-11-05 17:22:01,729 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eee4b510> to path /_matrix/client/api/v1
2018-11-05 17:22:01,729 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.media.v0.content_repository.ContentRepoResource instance at 0x7fb1eeebc680> to path /_matrix/content
2018-11-05 17:22:01,729 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.key.v2.KeyApiV2Resource instance at 0x7fb1eeebcea8> to path /_matrix/key/v2
2018-11-05 17:22:01,729 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <twisted.web.resource.EncodingResourceWrapper object at 0x7fb1eee4b510> to path /_matrix/client/v2_alpha
2018-11-05 17:22:01,729 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.key.v1.server_key_resource.LocalKey instance at 0x7fb1eeebc758> to path /_matrix/key/v1
2018-11-05 17:22:01,729 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.rest.media.v1.media_repository.MediaRepositoryResource instance at 0x7fb1eef2a8c0> to path /_matrix/media/r0
2018-11-05 17:22:01,730 - synapse.util.httpresourcetree - 46 - INFO - None- Attaching <synapse.federation.transport.server.TransportLayerServer object at 0x7fb1eee4b590> to path /_matrix/federation/v1
2018-11-05 17:22:01,730 - twisted - 243 - INFO - None- SynapseSite starting on 8008
2018-11-05 17:22:01,730 - synapse.app.homeserver - 175 - INFO - None- Synapse now listening on port 8008
2018-11-05 17:22:01,731 - synapse.app.homeserver - 562 - INFO - None- Scheduling stats reporting for 3 hour intervals
2018-11-05 17:22:01,732 - synapse.app.homeserver - 85 - INFO - - Running
2018-11-05 17:22:01,732 - synapse.app.homeserver - 30 - INFO - - Set file limit to: 1048576
2018-11-05 17:22:01,735 - synapse.handlers.deactivate_account - 134 - INFO - user_parter_loop-0- Starting user parter
2018-11-05 17:22:01,736 - synapse.storage.background_updates - 99 - INFO - background_updates-0- Starting background schema updates
2018-11-05 17:22:01,740 - synapse.app.homeserver - 511 - INFO - - report_stats can use psutil
2018-11-05 17:22:01,740 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:01,771 - synapse.handlers.deactivate_account - 144 - INFO - user_parter_loop-0- User parter finished: stopping
2018-11-05 17:22:01,784 - synapse.push.pusherpool - 201 - INFO - start_pushers-0- Starting 1 pushers
2018-11-05 17:22:01,785 - synapse.push.pusher - 55 - INFO - start_pushers-0- trying to create_pusher for {'lang': u'en', 'kind': u'http', 'failing_since': None, 'access_token': 110L, 'app_display_name': u'im.vector.alpha', 'device_display_name': u'BV8000Pro', 'app_id': u'im.vector.app.android', 'ts': 1541345713345L, 'profile_tag': u'mobile_477778950', 'last_stream_ordering': 1694641, 'last_success': 1541434695498L, 'data': {u'url': u'https://matrix.org/_matrix/push/v1/notify', u'format': u'event_id_only'}, 'pushkey': u'eaH89Uz0HB8:APA91bFEdChe3w_MsMOTMzT7pm9AMnwXeYaivah5eFlmCDM7aUuWYa43Y40o_KGB5bk1pcJMH2sHlX-e2E8l-msC9OjSjuROzog1ah7An8Vw1GlCd01BcW_W_97JfkOf1igy1tM-U5-HX_laiPZK0XvWBSF8Q4bPXQ', 'user_name': u'@nolan:thewordnerd.info', 'id': 193L}
2018-11-05 17:22:01,785 - synapse.push.pusher - 58 - INFO - start_pushers-0- found pusher
2018-11-05 17:22:01,786 - synapse.push.pusherpool - 204 - INFO - start_pushers-0- Started pushers
2018-11-05 17:22:01,796 - synapse.push.httppusher - 166 - INFO - httppush.process-0- Processing 0 unprocessed push actions for @nolan:thewordnerd.info/im.vector.app.android/eaH89Uz0HB8:APA91bFEdChe3w_MsMOTMzT7pm9AMnwXeYaivah5eFlmCDM7aUuWYa43Y40o_KGB5bk1pcJMH2sHlX-e2E8l-msC9OjSjuROzog1ah7An8Vw1GlCd01BcW_W_97JfkOf1igy1tM-U5-HX_laiPZK0XvWBSF8Q4bPXQ starting at stream_ordering 1694641
2018-11-05 17:22:02,738 - synapse.storage.background_updates - 113 - INFO - background_updates-0- No more background updates to do. Unscheduling background update task.
2018-11-05 17:22:04,130 - synapse.access.http.8008 - 233 - INFO - GET-0- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877706_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:22:04,133 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:04,141 - synapse.util.caches.response_cache - 151 - INFO - GET-0- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877706_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:22:04,145 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:06,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:11,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:11,738 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.001% {get_all_pushers(1): 0.000%, _update_client_ips_batch(2): 0.000%, get_rooms_for_user_where_membership_is(1): 0.000%} {}
2018-11-05 17:22:16,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:21,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:21,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, reap_monthly_active_users(0): 0.000%, get_users_pending_deactivation(0): 0.000%} {}
2018-11-05 17:22:26,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:31,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:31,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, reap_monthly_active_users(0): 0.000%, get_users_pending_deactivation(0): 0.000%} {}
2018-11-05 17:22:34,155 - synapse.handlers.sync - 898 - INFO - GET-0- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:22:34,164 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:34,347 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:34,620 - synapse.access.http.8008 - 302 - INFO - GET-0- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.489sec/0.000sec (0.051sec, 0.006sec) (0.013sec/0.432sec/24) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877706_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:22:34,781 - synapse.access.http.8008 - 233 - INFO - GET-1- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877706_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:22:34,783 - synapse.util.caches.response_cache - 151 - INFO - GET-1- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877706_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:22:34,784 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:36,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:22:36,693 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:36,734 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:36,825 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:36,829 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:22:36,905 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:36,956 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,011 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,057 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,092 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,141 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,179 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,223 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,272 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,332 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,384 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,398 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:22:37,445 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,485 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,549 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,601 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,656 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,697 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:37,735 - synapse.handlers.sync - 898 - INFO - GET-1- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:22:37,761 - synapse.access.http.8008 - 302 - INFO - GET-1- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 2.974sec/0.006sec (0.016sec, 0.003sec) (0.000sec/0.000sec/0) 3144B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877706_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:22:38,150 - synapse.access.http.8008 - 233 - INFO - GET-2- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:22:38,152 - synapse.util.caches.response_cache - 151 - INFO - GET-2- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:22:38,152 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:22:41,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:22:41,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:41,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.011% {get_rooms_for_user_where_membership_is(159): 0.005%, get_users_in_room(19): 0.004%, get_presence_list_accepted(160): 0.001%} {}
2018-11-05 17:22:46,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:22:46,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:51,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:22:51,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:22:51,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, reap_monthly_active_users(0): 0.000%} {}
2018-11-05 17:22:56,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:22:56,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:01,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:01,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:01,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {get_remote_profile_cache_entries_that_expire(1): 0.000%, _update_client_ips_batch(2): 0.000%, update_cached_last_access_time(1): 0.000%} {}
2018-11-05 17:23:06,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:06,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:08,153 - synapse.handlers.sync - 898 - INFO - GET-2- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:23:08,156 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:23:08,158 - synapse.access.http.8008 - 302 - INFO - GET-2- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.006sec/0.001sec (0.004sec, 0.001sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:23:08,439 - synapse.access.http.8008 - 233 - INFO - GET-3- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:23:08,442 - synapse.util.caches.response_cache - 151 - INFO - GET-3- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:23:11,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:11,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:11,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:23:16,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:16,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:21,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:21,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:21,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:23:26,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:26,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:31,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:31,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:31,750 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:23:36,568 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:23:36,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:36,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:38,443 - synapse.handlers.sync - 898 - INFO - GET-3- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:23:38,449 - synapse.access.http.8008 - 302 - INFO - GET-3- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.009sec/0.000sec (0.006sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:23:38,770 - synapse.access.http.8008 - 233 - INFO - GET-4- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:23:38,771 - synapse.util.caches.response_cache - 151 - INFO - GET-4- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:23:41,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:41,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:41,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:23:46,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:46,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:51,567 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:23:51,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:51,689 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:23:51,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:23:56,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:23:56,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:01,686 - synapse.handlers.presence - 257 - INFO - - Performing _persist_unpersisted_changes. Persisting 0 unpersisted changes
2018-11-05 17:24:01,686 - synapse.handlers.presence - 269 - INFO - - Finished _persist_unpersisted_changes
2018-11-05 17:24:01,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:01,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:01,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, get_remote_profile_cache_entries_that_expire(1): 0.000%, update_cached_last_access_time(1): 0.000%} {}
2018-11-05 17:24:06,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:06,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:08,773 - synapse.handlers.sync - 898 - INFO - GET-4- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:24:08,779 - synapse.access.http.8008 - 302 - INFO - GET-4- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.008sec/0.001sec (0.007sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:24:08,940 - synapse.access.http.8008 - 233 - INFO - GET-5- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:24:08,942 - synapse.util.caches.response_cache - 151 - INFO - GET-5- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:24:08,943 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:24:09,807 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:24:11,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:11,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:11,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:24:16,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:16,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:21,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:21,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:21,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:24:26,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:26,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:31,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:31,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:31,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:24:36,687 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:36,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:38,943 - synapse.handlers.sync - 898 - INFO - GET-5- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:24:38,949 - synapse.access.http.8008 - 302 - INFO - GET-5- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.008sec/0.001sec (0.008sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:24:39,168 - synapse.access.http.8008 - 233 - INFO - GET-6- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:24:39,170 - synapse.util.caches.response_cache - 151 - INFO - GET-6- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:24:39,170 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:24:41,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:41,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:41,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:24:46,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:46,691 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:51,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:51,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:24:51,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, update_presence(0): 0.000%, update_cached_last_access_time(0): 0.000%} {}
2018-11-05 17:24:56,687 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:24:56,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:01,686 - synapse.handlers.presence - 257 - INFO - - Performing _persist_unpersisted_changes. Persisting 0 unpersisted changes
2018-11-05 17:25:01,686 - synapse.handlers.presence - 269 - INFO - - Finished _persist_unpersisted_changes
2018-11-05 17:25:01,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:01,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:01,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {get_remote_profile_cache_entries_that_expire(1): 0.000%, _update_client_ips_batch(2): 0.000%, update_cached_last_access_time(1): 0.000%} {}
2018-11-05 17:25:03,262 - synapse.http.site - 203 - WARNING - GET-6- Error processing request <SynapseRequest at 0x7fb1efb983f8 method=u'GET' uri=u'/_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline' clientproto=u'HTTP/1.1' site=8008>: <class 'twisted.internet.error.ConnectionDone'> Connection was closed cleanly.
2018-11-05 17:25:05,802 - synapse.access.http.8008 - 233 - INFO - GET-7- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/pushrules/
2018-11-05 17:25:05,806 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:05,814 - synapse.access.http.8008 - 302 - INFO - GET-7- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 0.011sec/0.001sec (0.008sec, 0.000sec) (0.001sec/0.002sec/2) 572B 200 "GET /_matrix/client/r0/pushrules/ HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:25:06,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:06,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:07,618 - synapse.access.http.8008 - 233 - INFO - GET-8- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/profile/@nolan:thewordnerd.info/displayname
2018-11-05 17:25:07,627 - synapse.access.http.8008 - 302 - INFO - GET-8- ::ffff:195.201.35.232 - 8008 - {None} Processed request: 0.008sec/0.001sec (0.001sec, 0.000sec) (0.000sec/0.004sec/1) 44B 200 "GET /_matrix/client/r0/profile/@nolan:thewordnerd.info/displayname HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:25:07,951 - synapse.access.http.8008 - 233 - INFO - GET-9- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/voip/turnServer
2018-11-05 17:25:07,954 - synapse.access.http.8008 - 302 - INFO - GET-9- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 0.002sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 22B 200 "GET /_matrix/client/r0/voip/turnServer HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:25:07,956 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:07,958 - synapse.access.http.8008 - 233 - INFO - GET-10- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/profile/@nolan:thewordnerd.info/avatar_url
2018-11-05 17:25:07,960 - synapse.access.http.8008 - 302 - INFO - GET-10- ::ffff:195.201.35.232 - 8008 - {None} Processed request: 0.002sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.001sec/1) 22B 200 "GET /_matrix/client/r0/profile/@nolan:thewordnerd.info/avatar_url HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:25:08,124 - synapse.access.http.8008 - 233 - INFO - GET-11- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/account/3pid
2018-11-05 17:25:08,129 - synapse.access.http.8008 - 302 - INFO - GET-11- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 0.005sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 158B 200 "GET /_matrix/client/r0/account/3pid HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:25:09,171 - synapse.handlers.sync - 898 - INFO - GET-6- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:25:09,174 - synapse.http.server - 415 - WARNING - GET-6- Not sending response to request <SynapseRequest at 0x7fb1efb983f8 method=u'GET' uri=u'/_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline' clientproto=u'HTTP/1.1' site=8008>, already disconnected.
2018-11-05 17:25:09,175 - synapse.access.http.8008 - 302 - INFO - GET-6- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.007sec/-5.913sec (0.007sec, 0.001sec) (0.000sec/0.000sec/0) 0B 200! "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:25:09,176 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,088 - synapse.access.http.8008 - 233 - INFO - GET-12- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=0&filter=15&set_presence=offline
2018-11-05 17:25:11,091 - synapse.util.caches.response_cache - 151 - INFO - GET-12- [sync]: no cached result for [(@nolan:thewordnerd.info, 0, None, u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:25:11,091 - synapse.handlers.sync - 898 - INFO - GET-12- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:25:11,101 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,198 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,227 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,268 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,316 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,344 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,370 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,380 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:25:11,393 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,409 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,424 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,448 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,479 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,509 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,559 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,607 - synapse.util.async_helpers - 205 - INFO - GET-12- Acquired uncontended linearizer lock 'state_resolve_lock' for key frozenset([619488L, 591800L])
2018-11-05 17:25:11,607 - synapse.state - 476 - INFO - GET-12- Resolving state for !skaicEwTmKWZLelzSj:matrix.org with 2 groups
2018-11-05 17:25:11,608 - synapse.state - 497 - INFO - GET-12- Resolving conflicted state for u'!skaicEwTmKWZLelzSj:matrix.org'
2018-11-05 17:25:11,631 - synapse.state.v1 - 75 - INFO - GET-12- Asking for 312/312 conflicted events
2018-11-05 17:25:11,635 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,647 - synapse.util.async_helpers - 205 - INFO - GET-12- Acquired uncontended linearizer lock 'state_resolve_lock' for key frozenset([477539L, 506249L, 571890L, 465177L, 571576L, 619481L])
2018-11-05 17:25:11,647 - synapse.state - 476 - INFO - GET-12- Resolving state for !UMOdWVcgceMwDXgWtC:matrix.org with 6 groups
2018-11-05 17:25:11,649 - synapse.state - 497 - INFO - GET-12- Resolving conflicted state for u'!UMOdWVcgceMwDXgWtC:matrix.org'
2018-11-05 17:25:11,665 - synapse.state.v1 - 75 - INFO - GET-12- Asking for 544/544 conflicted events
2018-11-05 17:25:11,690 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:11,699 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:11,700 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:11,847 - synapse.state.v1 - 101 - INFO - GET-12- Asking for 4/4 auth events
2018-11-05 17:25:11,854 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.011% {_get_state_groups_from_groups(20): 0.004%, do_fetch(26): 0.003%, get_current_state_ids(2): 0.001%} {}
2018-11-05 17:25:11,854 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:12,099 - synapse.state.v1 - 101 - INFO - GET-12- Asking for 3/3 auth events
2018-11-05 17:25:12,299 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:12,354 - synapse.util.async_helpers - 218 - INFO - GET-12- Releasing linearizer lock 'state_resolve_lock' for key frozenset([619488L, 591800L])
2018-11-05 17:25:12,485 - synapse.util.async_helpers - 218 - INFO - GET-12- Releasing linearizer lock 'state_resolve_lock' for key frozenset([477539L, 506249L, 571890L, 465177L, 571576L, 619481L])
2018-11-05 17:25:12,523 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:25:12,561 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:12,678 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:12,694 - synapse.util.async_helpers - 205 - INFO - GET-12- Acquired uncontended linearizer lock 'state_resolve_lock' for key frozenset([571888L, 469569L, 471634L, 619491L, 465259L])
2018-11-05 17:25:12,694 - synapse.state - 476 - INFO - GET-12- Resolving state for !jxkfScGlHataTUWUFW:matrix.org with 5 groups
2018-11-05 17:25:12,701 - synapse.state - 497 - INFO - GET-12- Resolving conflicted state for u'!jxkfScGlHataTUWUFW:matrix.org'
2018-11-05 17:25:12,775 - synapse.state.v1 - 75 - INFO - GET-12- Asking for 3667/3667 conflicted events
2018-11-05 17:25:12,793 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:12,827 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:12,854 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:12,912 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:12,957 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:13,029 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:13,269 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:13,934 - synapse.state.v1 - 101 - INFO - GET-12- Asking for 3/3 auth events
2018-11-05 17:25:14,300 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:14,623 - synapse.util.async_helpers - 218 - INFO - GET-12- Releasing linearizer lock 'state_resolve_lock' for key frozenset([571888L, 469569L, 471634L, 619491L, 465259L])
2018-11-05 17:25:14,651 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:14,788 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:25:14,873 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:14,925 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:15,047 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:15,334 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:17,046 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:17,049 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:17,049 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:17,221 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:17,454 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:17,561 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:17,605 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:17,656 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:17,683 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:17,695 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:25:17,833 - synapse.metrics - 374 - INFO - - Collecting gc 2
2018-11-05 17:25:18,194 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:18,213 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:18,222 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:18,336 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:18,950 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:22,157 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:22,158 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:22,159 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.090% {_get_state_groups_from_groups(35): 0.044%, do_fetch(52): 0.031%, _get_state_group_for_events(23): 0.006%} {}
2018-11-05 17:25:22,164 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:22,448 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:22,495 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:22,520 - synapse.util.async_helpers - 205 - INFO - GET-12- Acquired uncontended linearizer lock 'state_resolve_lock' for key frozenset([616259L, 611684L, 604264L, 598537L, 616268L, 604046L, 600114L, 609300L, 605870L, 619451L, 605598L, 611743L])
2018-11-05 17:25:22,520 - synapse.state - 476 - INFO - GET-12- Resolving state for !SudviOJlimDvrGdFCY:matrix.org with 12 groups
2018-11-05 17:25:22,535 - synapse.state - 497 - INFO - GET-12- Resolving conflicted state for u'!SudviOJlimDvrGdFCY:matrix.org'
2018-11-05 17:25:22,678 - synapse.state.v1 - 75 - INFO - GET-12- Asking for 1302/1302 conflicted events
2018-11-05 17:25:22,682 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:22,914 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:23,199 - synapse.state.v1 - 101 - INFO - GET-12- Asking for 4/4 auth events
2018-11-05 17:25:23,435 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:23,773 - synapse.util.async_helpers - 218 - INFO - GET-12- Releasing linearizer lock 'state_resolve_lock' for key frozenset([616259L, 611684L, 604264L, 598537L, 616268L, 604046L, 600114L, 609300L, 605870L, 619451L, 605598L, 611743L])
2018-11-05 17:25:23,791 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:25:24,149 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:24,177 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:24,355 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:24,362 - synapse.util.async_helpers - 205 - INFO - GET-12- Acquired uncontended linearizer lock 'state_resolve_lock' for key frozenset([571881L, 612954L, 571629L])
2018-11-05 17:25:24,362 - synapse.state - 476 - INFO - GET-12- Resolving state for !LwDAdUFMMmlqOEcKKv:matrix.org with 3 groups
2018-11-05 17:25:24,365 - synapse.state - 497 - INFO - GET-12- Resolving conflicted state for u'!LwDAdUFMMmlqOEcKKv:matrix.org'
2018-11-05 17:25:24,380 - synapse.state.v1 - 75 - INFO - GET-12- Asking for 410/410 conflicted events
2018-11-05 17:25:24,720 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:24,861 - synapse.state.v1 - 101 - INFO - GET-12- Asking for 4/4 auth events
2018-11-05 17:25:26,065 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:26,193 - synapse.util.async_helpers - 218 - INFO - GET-12- Releasing linearizer lock 'state_resolve_lock' for key frozenset([571881L, 612954L, 571629L])
2018-11-05 17:25:26,295 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:26,940 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:26,945 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:26,948 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:27,076 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:27,129 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:27,170 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:27,213 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:27,217 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:25:27,541 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:30,553 - synapse.access.http.8008 - 302 - INFO - GET-12- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 18.301sec/1.164sec (13.023sec, 1.307sec) (0.545sec/8.489sec/325) 2620176B 200 "GET /_matrix/client/r0/sync?timeout=0&filter=15&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [47974 dbevts]
2018-11-05 17:25:31,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:31,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:31,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.025% {do_fetch(19): 0.007%, get_presence_for_users(62): 0.005%, get_current_state_ids(2): 0.004%} {}
2018-11-05 17:25:36,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:36,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:36,912 - synapse.access.http.8008 - 233 - INFO - GET-13- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:25:36,914 - synapse.util.caches.response_cache - 151 - INFO - GET-13- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:25:41,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:41,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:41,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:25:46,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:46,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:51,568 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:25:51,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:51,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:25:51,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:25:54,110 - synapse.access.http.8008 - 233 - INFO - POST-14- ::ffff:195.201.35.232 - 8008 - Received request: POST /_matrix/client/unstable/keys/upload/VQCKYJKNRJ
2018-11-05 17:25:54,112 - synapse.handlers.e2e_keys - 273 - INFO - POST-14- Updating device_keys for device u'VQCKYJKNRJ' for user @nolan:thewordnerd.info at 1541438754112
2018-11-05 17:25:54,120 - synapse.access.http.8008 - 302 - INFO - POST-14- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 0.010sec/0.001sec (0.006sec, 0.001sec) (0.001sec/0.003sec/2) 69B 200 "POST /_matrix/client/unstable/keys/upload/VQCKYJKNRJ HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:25:56,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:25:56,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:01,677 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:26:01,686 - synapse.handlers.presence - 257 - INFO - - Performing _persist_unpersisted_changes. Persisting 0 unpersisted changes
2018-11-05 17:26:01,686 - synapse.handlers.presence - 269 - INFO - - Finished _persist_unpersisted_changes
2018-11-05 17:26:01,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:01,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:01,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {get_remote_profile_cache_entries_that_expire(1): 0.000%, set_e2e_device_keys(1): 0.000%, _update_client_ips_batch(2): 0.000%} {}
2018-11-05 17:26:06,687 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:06,690 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:06,915 - synapse.handlers.sync - 898 - INFO - GET-13- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:26:06,921 - synapse.access.http.8008 - 302 - INFO - GET-13- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.007sec/0.001sec (0.006sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:26:07,282 - synapse.access.http.8008 - 233 - INFO - GET-15- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:26:07,284 - synapse.util.caches.response_cache - 151 - INFO - GET-15- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:26:11,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:11,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:11,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:26:16,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:16,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:21,567 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:26:21,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:21,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:21,738 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:26:26,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:26,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:31,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:31,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:31,738 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:26:36,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:36,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:37,286 - synapse.handlers.sync - 898 - INFO - GET-15- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:26:37,291 - synapse.access.http.8008 - 302 - INFO - GET-15- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.007sec/0.002sec (0.005sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:26:37,532 - synapse.access.http.8008 - 233 - INFO - GET-16- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:26:37,534 - synapse.util.caches.response_cache - 151 - INFO - GET-16- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:26:41,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:41,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:41,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:26:46,567 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:26:46,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:46,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:51,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:51,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:26:51,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:26:56,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:26:56,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:01,686 - synapse.handlers.presence - 257 - INFO - - Performing _persist_unpersisted_changes. Persisting 0 unpersisted changes
2018-11-05 17:27:01,686 - synapse.handlers.presence - 269 - INFO - - Finished _persist_unpersisted_changes
2018-11-05 17:27:01,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:01,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:01,732 - synapse.storage - 371 - INFO - generate_user_daily_visits-0- Calling _generate_user_daily_visits
2018-11-05 17:27:01,732 - synapse.app.homeserver - 450 - INFO - phone_stats_home-0- Gathering stats for reporting
2018-11-05 17:27:01,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {generate_user_daily_visits(1): 0.000%, _update_client_ips_batch(2): 0.000%, get_remote_profile_cache_entries_that_expire(1): 0.000%} {}
2018-11-05 17:27:01,753 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:27:01,778 - synapse.app.homeserver - 495 - INFO - phone_stats_home-0- Reporting stats to matrix.org: {'daily_sent_messages': 0L, 'python_version': '2.7.15', 'total_nonbridged_users': 2L, 'event_cache_size': 10240, 'daily_active_rooms': 10L, 'daily_messages': 496L, 'daily_active_users': 1L, 'r30_users_all': 2L, 'total_room_count': 60L, u'r30_users_unknown': 2L, 'timestamp': 1541438821, 'cpu_average': 6, 'daily_user_type_bridged': 0, 'daily_user_type_guest': 0, 'total_users': 2L, u'r30_users_android': 1L, 'uptime_seconds': 299, 'memory_rss': 721178624, 'cache_factor': 0.5, 'homeserver': 'thewordnerd.info', u'r30_users_web': 1L, 'daily_user_type_native': 0}
2018-11-05 17:27:01,779 - synapse.http.client - 96 - INFO - phone_stats_home-0- Sending request PUT https://matrix.org/report-usage-stats/push
2018-11-05 17:27:01,813 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:27:01,876 - synapse.http.client - 111 - INFO - phone_stats_home-0- Received response to  PUT https://matrix.org/report-usage-stats/push: 200
2018-11-05 17:27:06,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:06,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:07,535 - synapse.handlers.sync - 898 - INFO - GET-16- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:27:07,540 - synapse.access.http.8008 - 302 - INFO - GET-16- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.007sec/0.001sec (0.006sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:27:07,877 - synapse.access.http.8008 - 233 - INFO - GET-17- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:27:07,879 - synapse.util.caches.response_cache - 151 - INFO - GET-17- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:27:11,566 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:27:11,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:11,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:11,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {count_users(3): 0.000%, _update_client_ips_batch(2): 0.000%, count_daily_active_rooms(1): 0.000%} {}
2018-11-05 17:27:16,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:16,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:21,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:21,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:21,738 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:27:26,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:26,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:31,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:31,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:31,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:27:36,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:36,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:37,879 - synapse.handlers.sync - 898 - INFO - GET-17- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:27:37,883 - synapse.access.http.8008 - 302 - INFO - GET-17- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.005sec/0.001sec (0.005sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:27:38,177 - synapse.access.http.8008 - 233 - INFO - GET-18- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:27:38,179 - synapse.util.caches.response_cache - 151 - INFO - GET-18- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:27:38,180 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:27:41,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:41,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:41,739 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:27:46,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:46,689 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:51,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:51,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:27:51,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:27:56,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:27:56,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:01,688 - synapse.handlers.presence - 257 - INFO - - Performing _persist_unpersisted_changes. Persisting 0 unpersisted changes
2018-11-05 17:28:01,689 - synapse.handlers.presence - 269 - INFO - - Finished _persist_unpersisted_changes
2018-11-05 17:28:01,689 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:01,690 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:01,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {get_remote_profile_cache_entries_that_expire(1): 0.000%, _update_client_ips_batch(2): 0.000%, update_cached_last_access_time(1): 0.000%} {}
2018-11-05 17:28:06,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:06,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:08,180 - synapse.handlers.sync - 898 - INFO - GET-18- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:28:08,186 - synapse.access.http.8008 - 302 - INFO - GET-18- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.008sec/0.001sec (0.005sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:28:08,359 - synapse.access.http.8008 - 233 - INFO - GET-19- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:28:08,360 - synapse.util.caches.response_cache - 151 - INFO - GET-19- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:28:08,361 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:28:11,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:11,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:11,738 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:28:16,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:16,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:21,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:21,686 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:21,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:28:26,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:26,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:31,688 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:31,689 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:31,737 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:28:36,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:36,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:38,363 - synapse.handlers.sync - 898 - INFO - GET-19- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:28:38,370 - synapse.access.http.8008 - 302 - INFO - GET-19- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.011sec/0.001sec (0.009sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:28:38,616 - synapse.access.http.8008 - 233 - INFO - GET-20- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:28:38,618 - synapse.util.caches.response_cache - 151 - INFO - GET-20- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:28:38,619 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:28:39,554 - synapse.metrics - 374 - INFO - - Collecting gc 1
2018-11-05 17:28:41,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:41,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:41,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:28:46,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:46,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:51,688 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:51,689 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:28:51,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:28:56,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:28:56,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:29:01,690 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:29:01,693 - synapse.handlers.presence - 257 - INFO - - Performing _persist_unpersisted_changes. Persisting 0 unpersisted changes
2018-11-05 17:29:01,693 - synapse.handlers.presence - 269 - INFO - - Finished _persist_unpersisted_changes
2018-11-05 17:29:01,693 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:29:01,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {get_remote_profile_cache_entries_that_expire(1): 0.000%, _update_client_ips_batch(2): 0.000%, update_cached_last_access_time(1): 0.000%} {}
2018-11-05 17:29:06,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:29:06,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:29:08,620 - synapse.handlers.sync - 898 - INFO - GET-20- Calculating sync response for @nolan:thewordnerd.info
2018-11-05 17:29:08,625 - synapse.access.http.8008 - 302 - INFO - GET-20- ::ffff:195.201.35.232 - 8008 - {@nolan:thewordnerd.info} Processed request: 30.008sec/0.001sec (0.007sec, 0.000sec) (0.000sec/0.000sec/0) 211B 200 "GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline HTTP/1.1" "Riot.im/0.8.18 (Linux; U; Android 7.0; BV8000Pro Build/NRD90; Flavour GooglePlay; MatrixAndroidSDK 0.9.12)" [0 dbevts]
2018-11-05 17:29:08,795 - synapse.access.http.8008 - 233 - INFO - GET-21- ::ffff:195.201.35.232 - 8008 - Received request: GET /_matrix/client/r0/sync?timeout=30000&filter=15&since=s1694642_47877865_0_1733167_537_9_15_177744_1&set_presence=offline
2018-11-05 17:29:08,800 - synapse.util.caches.response_cache - 151 - INFO - GET-21- [sync]: no cached result for [(@nolan:thewordnerd.info, 30000, u's1694642_47877865_0_1733167_537_9_15_177744_1', u'15', False, u'VQCKYJKNRJ')], calculating new one
2018-11-05 17:29:08,800 - synapse.metrics - 374 - INFO - - Collecting gc 0
2018-11-05 17:29:11,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:29:11,689 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:29:11,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:29:16,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:29:16,688 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:29:21,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:29:21,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:29:21,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}
2018-11-05 17:29:26,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:29:26,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:29:31,686 - synapse.handlers.presence - 350 - INFO - - Handling presence timeouts
2018-11-05 17:29:31,687 - synapse.handlers.typing - 83 - INFO - - Checking for typing timeouts
2018-11-05 17:29:31,736 - synapse.storage.TIME - 218 - INFO - - Total database time: 0.000% {_update_client_ips_batch(2): 0.000%, user_get_threepids(0): 0.000%, update_presence(0): 0.000%} {}