Moderator action logging failing
Opened this issue · 1 comments
mrphlip commented
When we get a moderator action, trying to log that (to Slack, for #loadingreadyrun, or to GDocs, for #desertbus) is failing.
I suspect the default timeout of 5 seconds is just way too short? 30 is closer to the norm I've seen elsewhere... other http things are also frequently failing with timeouts.
#loadingreadyrun example
[2017-11-14 12:44:54,760] DEBUG:common.pubsub:New message: {'data': {'topic': 'chat_moderator_actions.54568973.27132299', 'message': '{"data":{"type":"chat_login_moderation","moderation_action":"timeout","args":["cusk_assbiefef","1","testing a thing"],"created_by":"mrphlip","created_by_user_id":"25875159","msg_id":"","target_user_id":"150631270"}}'}, 'type': 'MESSAGE'}
[2017-11-14 12:44:54,761] INFO:moderator_actions:Got message: {'msg_id': '', 'args': ['cusk_assbiefef', '1', 'testing a thing'], 'moderation_action': 'timeout', 'created_by': 'mrphlip', 'created_by_user_id': '25875159', 'type': 'chat_login_moderation', 'target_user_id': '150631270'}
[2017-11-14 12:44:55,007] DEBUG:common.http:POST 'https://hooks.slack.com/services/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'...
[2017-11-14 12:45:00,009] INFO:common.http:Downloading https://hooks.slack.com/services/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 failed: TimeoutError: , retrying...
[2017-11-14 12:45:00,011] DEBUG:common.http:POST 'https://hooks.slack.com/services/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'...
[2017-11-14 12:45:05,013] INFO:common.http:Downloading https://hooks.slack.com/services/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 failed: TimeoutError: , retrying...
[2017-11-14 12:45:05,015] DEBUG:common.http:POST 'https://hooks.slack.com/services/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'...
[2017-11-14 12:45:10,016] ERROR:utils:Exception in future
Traceback (most recent call last):
File "/srv/lrrbot/lrrbot/common/http.py", line 95, in request_coro
async with http_request_session.request(method, url, params=params, data=data, headers=headers, allow_redirects=allow_redirects) as res:
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/client.py", line 692, in __aenter__
self._resp = yield from self._coro
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/client.py", line 269, in _request
conn = yield from self._connector.connect(req)
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/connector.py", line 379, in connect
yield from fut
File "/usr/lib64/python3.5/asyncio/futures.py", line 381, in __iter__
yield self # This tells Task to wait for completion.
File "/usr/lib64/python3.5/asyncio/tasks.py", line 310, in _wakeup
future.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 286, in result
raise CancelledError
concurrent.futures._base.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/srv/lrrbot/lrrbot/common/utils.py", line 241, in check_exception
future.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 294, in result
raise self._exception
File "/usr/lib64/python3.5/asyncio/tasks.py", line 242, in _step
result = coro.throw(exc)
File "/srv/lrrbot/lrrbot/common/slack.py", line 14, in send_message
await http.request_coro(config['slack_webhook_url'], method="POST", data=json.dumps(keys), headers=headers)
File "/srv/lrrbot/lrrbot/common/http.py", line 116, in request_coro
raise firstex
File "/srv/lrrbot/lrrbot/common/http.py", line 105, in request_coro
return text
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/async_timeout/__init__.py", line 35, in __exit__
self._do_exit(exc_type)
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/async_timeout/__init__.py", line 80, in _do_exit
raise asyncio.TimeoutError
concurrent.futures._base.TimeoutError
#desertbus example:
[2017-11-14 12:49:13,987] DEBUG:common.pubsub:New message: {'data': {'topic': 'chat_moderator_actions.25875159.24856654', 'message': '{"data":{"type":"chat_login_moderation","moderation_action":"timeout","args":["cusk_assbiefef","1","Testing mod action logging"],"created_by":"mrphlip","created_by_user_id":"25875159","msg_id":"","target_user_id":"150631270"}}'}, 'type': 'MESSAGE'}
[2017-11-14 12:49:13,988] DEBUG:desertbus_moderator_actions:Add row: [('Timestamp', '2017-11-14 04:49:13'), ('Timestamp (hours bussed)', '-77:10:47'), ("Offender's Username", 'cusk_assbiefef'), ('Moderator', 'mrphlip'), ('Enforcement option/length', 'Timeout: 1s'), ('What was the cause of the enforcement action?', 'Testing mod action logging'), ('Last Line', '')]
[2017-11-14 12:49:13,992] DEBUG:common.http:POST 'https://accounts.google.com/o/oauth2/token'...
[2017-11-14 12:49:18,998] INFO:common.http:Downloading https://accounts.google.com/o/oauth2/token failed: TimeoutError: , retrying...
[2017-11-14 12:49:18,998] DEBUG:common.http:POST 'https://accounts.google.com/o/oauth2/token'...
[2017-11-14 12:49:24,004] INFO:common.http:Downloading https://accounts.google.com/o/oauth2/token failed: TimeoutError: , retrying...
[2017-11-14 12:49:24,005] DEBUG:common.http:POST 'https://accounts.google.com/o/oauth2/token'...
[2017-11-14 12:49:29,011] ERROR:utils:Exception in future
Traceback (most recent call last):
File "/srv/lrrbot/lrrbot/common/http.py", line 95, in request_coro
async with http_request_session.request(method, url, params=params, data=data, headers=headers, allow_redirects=allow_redirects) as res:
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/client.py", line 692, in __aenter__
self._resp = yield from self._coro
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/client.py", line 269, in _request
conn = yield from self._connector.connect(req)
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/connector.py", line 379, in connect
yield from fut
File "/usr/lib64/python3.5/asyncio/futures.py", line 381, in __iter__
yield self # This tells Task to wait for completion.
File "/usr/lib64/python3.5/asyncio/tasks.py", line 310, in _wakeup
future.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 286, in result
raise CancelledError
concurrent.futures._base.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/srv/lrrbot/lrrbot/common/utils.py", line 241, in check_exception
future.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 294, in result
raise self._exception
File "/usr/lib64/python3.5/asyncio/tasks.py", line 242, in _step
result = coro.throw(exc)
File "/srv/lrrbot/lrrbot/common/gdata.py", line 60, in add_rows_to_spreadsheet
token = await get_oauth_token(["https://spreadsheets.google.com/feeds"])
File "/srv/lrrbot/lrrbot/common/gdata.py", line 43, in get_oauth_token
ret = json.loads((await common.http.request_coro("https://accounts.google.com/o/oauth2/token", data, "POST")))
File "/srv/lrrbot/lrrbot/common/http.py", line 116, in request_coro
raise firstex
File "/srv/lrrbot/lrrbot/common/http.py", line 105, in request_coro
return text
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/async_timeout/__init__.py", line 35, in __exit__
self._do_exit(exc_type)
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/async_timeout/__init__.py", line 80, in _do_exit
raise asyncio.TimeoutError
concurrent.futures._base.TimeoutError
mrphlip commented
Noep, still timing out even with a 30-second timeout :-/
[2017-11-16 23:06:05,779] ERROR:utils:Exception in future
Traceback (most recent call last):
File "/srv/lrrbot/lrrbot/common/http.py", line 95, in request_coro
async with http_request_session.request(method, url, params=params, data=data, headers=headers, allow_redirects=allow_redirects) as res:
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/client.py", line 692, in __aenter__
self._resp = yield from self._coro
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/client.py", line 269, in _request
conn = yield from self._connector.connect(req)
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/aiohttp/connector.py", line 380, in connect
yield from fut
File "/usr/lib64/python3.5/asyncio/futures.py", line 381, in __iter__
yield self # This tells Task to wait for completion.
File "/usr/lib64/python3.5/asyncio/tasks.py", line 310, in _wakeup
future.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 286, in result
raise CancelledError
concurrent.futures._base.CancelledError
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/srv/lrrbot/lrrbot/common/utils.py", line 241, in check_exception
future.result()
File "/usr/lib64/python3.5/asyncio/futures.py", line 294, in result
raise self._exception
File "/usr/lib64/python3.5/asyncio/tasks.py", line 242, in _step
result = coro.throw(exc)
File "/srv/lrrbot/lrrbot/common/gdata.py", line 60, in add_rows_to_spreadsheet
token = await get_oauth_token(["https://spreadsheets.google.com/feeds"])
File "/srv/lrrbot/lrrbot/common/gdata.py", line 43, in get_oauth_token
ret = json.loads((await common.http.request_coro("https://accounts.google.com/o/oauth2/token", data, "POST")))
File "/srv/lrrbot/lrrbot/common/http.py", line 116, in request_coro
raise firstex
File "/srv/lrrbot/lrrbot/common/http.py", line 105, in request_coro
return text
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/async_timeout/__init__.py", line 35, in __exit__
self._do_exit(exc_type)
File "/srv/lrrbot/lrrbot/venv/lib/python3.5/site-packages/async_timeout/__init__.py", line 80, in _do_exit
raise asyncio.TimeoutError
concurrent.futures._base.TimeoutError