search

freiheit / discord_feedbot

Moved to https://gitlab.com/ffreiheit/discord_feedbot
MIT License
82 stars 28 forks source link

ERROR:asyncio:Unclosed client session #38

Closed nEo-1664 closed 7 years ago

nEo-1664 commented 8 years ago

C:\Python34\discord\discord_feedbot>python feed2discord.py WARNING:discord.client:PyNaCl is not installed, voice will NOT be supported INFO:main:ednews: Starting up background_check_feed INFO:main:status: Starting up background_check_feed C:\Python34\lib\site-packages\aiohttp-1.0.5-py3.4.egg\aiohttp\client.py:88: Reso urceWarning: Unclosed client session <aiohttp.client.ClientSession object at 0x0 000000003BBE6D8> C:\Python34\lib\importlib_bootstrap.py:2150: ImportWarning: sys.meta_path is em pty ERROR:asyncio:Unclosed client session client_session: <aiohttp.client.ClientSession object at 0x0000000003BBE6D8> ERROR:asyncio:Task was destroyed but it is pending! task: <Task pending coro=<background_check_feed() running at feed2discord.py:331

wait_for=> ERROR:asyncio:Task was destroyed but it is pending! task: <Task pending coro=<background_check_feed() running at feed2discord.py:331 wait_for=>

freiheit commented 8 years ago

Can you please increase the debug level (in the ini file), run that again and see what it says?

nEo-1664 commented 8 years ago 
C:\Python34\discord\discord_feedbot>python feed2discord.py
DEBUG:asyncio:Using selector: SelectSelector
WARNING:discord.client:PyNaCl is not installed, voice will NOT be supported
INFO:discord.client:on_ready has successfully been registered as an event
INFO:__main__:ednews: Starting up background_check_feed
INFO:__main__:status: Starting up background_check_feed
INFO:discord.client:logging in using static token
DEBUG:asyncio:Get address info discordapp.com:443, type=<SocketKind.SOCK_STREAM:
 1>
WARNING:asyncio:Executing <Task pending coro=<login() running at C:\Python34\lib
\site-packages\discord.py-0.14.2-py3.4.egg\discord\client.py:416> wait_for=<Futu
re pending cb=[wrap_future.<locals>._check_cancel_other() at C:\Python34\lib\asy
ncio\futures.py:401, Task._wakeup()] created at C:\Python34\lib\asyncio\futures.
py:399> cb=[_run_until_complete_cb() at C:\Python34\lib\asyncio\base_events.py:1
23] created at C:\Python34\lib\asyncio\base_events.py:296> took 0.688 seconds
DEBUG:asyncio:Getting address info discordapp.com:443, type=<SocketKind.SOCK_STR
EAM: 1> took 0.000 ms: [(<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>
, 0, '', ('104.16.58.5', 443)), (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_ST
REAM: 1>, 0, '', ('104.16.59.5', 443))]
DEBUG:asyncio:poll 299312.000 ms took 15.000 ms: 1 events
DEBUG:asyncio:Get address info 104.16.58.5:443, family=<AddressFamily.AF_INET: 2
>, type=<SocketKind.SOCK_STREAM: 1>, flags=4
DEBUG:asyncio:Getting address info 104.16.58.5:443, family=<AddressFamily.AF_INE
T: 2>, type=<SocketKind.SOCK_STREAM: 1>, flags=4 took 0.000 ms: [(<AddressFamily
.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 0, '', ('104.16.58.5', 443))]
DEBUG:asyncio:connect <socket.socket fd=464, family=AddressFamily.AF_INET, type=
SocketKind.SOCK_STREAM, proto=0> to ('104.16.58.5', 443)
DEBUG:asyncio:poll 299297.000 ms took 16.000 ms: 1 events
DEBUG:asyncio:<_SelectorSslTransport fd=464 read=idle write=<idle, bufsize=0>> s
tarts SSL handshake
DEBUG:asyncio:poll 299266.000 ms took 0.000 ms: 1 events
WARNING:asyncio:<_SelectorSslTransport fd=464 read=polling write=<idle, bufsize=
0>>: SSL handshake failed
Traceback (most recent call last):
  File "C:\Python34\lib\asyncio\selector_events.py", line 802, in _on_handshake
    self._sock.do_handshake()
  File "C:\Python34\lib\ssl.py", line 810, in do_handshake
    self._sslobj.do_handshake()
ssl.SSLError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c
:600)
DEBUG:asyncio:Get address info 104.16.59.5:443, family=<AddressFamily.AF_INET: 2
>, type=<SocketKind.SOCK_STREAM: 1>, flags=4
DEBUG:asyncio:Getting address info 104.16.59.5:443, family=<AddressFamily.AF_INE
T: 2>, type=<SocketKind.SOCK_STREAM: 1>, flags=4 took 0.000 ms: [(<AddressFamily
.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 0, '', ('104.16.59.5', 443))]
DEBUG:asyncio:poll 299250.000 ms took 0.000 ms: 1 events
DEBUG:asyncio:connect <socket.socket fd=464, family=AddressFamily.AF_INET, type=
SocketKind.SOCK_STREAM, proto=0> to ('104.16.59.5', 443)
DEBUG:asyncio:poll 299250.000 ms took 16.000 ms: 1 events
DEBUG:asyncio:<_SelectorSslTransport fd=464 read=idle write=<idle, bufsize=0>> s
tarts SSL handshake
DEBUG:asyncio:poll 299234.000 ms took 15.000 ms: 1 events
WARNING:asyncio:<_SelectorSslTransport fd=464 read=polling write=<idle, bufsize=
0>>: SSL handshake failed
Traceback (most recent call last):
  File "C:\Python34\lib\asyncio\selector_events.py", line 802, in _on_handshake
    self._sock.do_handshake()
  File "C:\Python34\lib\ssl.py", line 810, in do_handshake
    self._sslobj.do_handshake()
ssl.SSLError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c
:600)
DEBUG:asyncio:Close <_WindowsSelectorEventLoop running=False closed=False debug=
True>
C:\Python34\lib\site-packages\aiohttp-1.0.5-py3.4.egg\aiohttp\client.py:88: Reso
urceWarning: Unclosed client session <aiohttp.client.ClientSession object at 0x0
0000000031BE6A0>
C:\Python34\lib\importlib\_bootstrap.py:2150: ImportWarning: sys.meta_path is em
pty
ERROR:asyncio:Unclosed client session
client_session: <aiohttp.client.ClientSession object at 0x00000000031BE6A0>
source_traceback: Object created at (most recent call last):
  File "feed2discord.py", line 93, in <module>
    httpclient = aiohttp.ClientSession()
ERROR:asyncio:Task was destroyed but it is pending!
source_traceback: Object created at (most recent call last):
  File "feed2discord.py", line 692, in <module>
    loop.create_task(background_check_feed(feed,loop))
task: <Task pending coro=<background_check_feed() running at feed2discord.py:331
> wait_for=<Future pending cb=[Task._wakeup()] created at C:\Python34\lib\asynci
o\locks.py:239> created at feed2discord.py:692>
ERROR:asyncio:Task was destroyed but it is pending!
source_traceback: Object created at (most recent call last):
  File "feed2discord.py", line 692, in <module>
    loop.create_task(background_check_feed(feed,loop))
task: <Task pending coro=<background_check_feed() running at feed2discord.py:331
> wait_for=<Future pending cb=[Task._wakeup()] created at C:\Python34\lib\asynci
o\locks.py:239> created at feed2discord.py:692>
freiheit commented 8 years ago 
DEBUG:asyncio:Getting address info discordapp.com:443, type=<SocketKind.SOCK_STR
EAM: 1> took 0.000 ms: [(<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>
, 0, '', ('104.16.58.5', 443)), (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_ST
REAM: 1>, 0, '', ('104.16.59.5', 443))]

...

WARNING:asyncio:<_SelectorSslTransport fd=464 read=polling write=<idle, bufsize=
0>>: SSL handshake failed
Traceback (most recent call last):
  File "C:\Python34\lib\asyncio\selector_events.py", line 802, in _on_handshake
    self._sock.do_handshake()
  File "C:\Python34\lib\ssl.py", line 810, in do_handshake
    self._sslobj.do_handshake()
ssl.SSLError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c
:600)

Looks like you're getting an SSL certificate verification error when talking to discordapp.com.

On the system you're trying to run the bot on, try: curl --head https://discordapp.com/ or echo | openssl s_client -verify 10 -connect discordapp.com:443

Looks like maybe your system is missing the SSL certificate authority stuff. Or maybe there's a proxy in between your system and the internet that's breaking things?

nEo-1664 commented 8 years ago

openssl is not recognised as an internal or external command.

Does this need to be run under the python console, or straight into cmd?

nEo-1664 commented 8 years ago

ok, that seems to have resolved itself if I'm honest... but it's producing a different one;

ERROR:asyncio:Task exception was never retrieved
future: <Task finished coro=<actually_send_message() done, defined at feed2disco
rd.py:306> exception=HTTPException('BAD REQUEST (status code: 400)',) created at
 feed2discord.py:302>
source_traceback: Object created at (most recent call last):
  File "feed2discord.py", line 698, in <module>
    loop.run_until_complete(client.connect())
  File "C:\Python34\lib\asyncio\base_events.py", line 304, in run_until_complete

    self.run_forever()
  File "C:\Python34\lib\asyncio\base_events.py", line 276, in run_forever
    self._run_once()
  File "C:\Python34\lib\asyncio\base_events.py", line 1164, in _run_once
    handle._run()
  File "C:\Python34\lib\asyncio\events.py", line 120, in _run
    self._callback(*self._args)
  File "C:\Python34\lib\asyncio\tasks.py", line 292, in _wakeup
    self._step(value, None)
  File "C:\Python34\lib\asyncio\tasks.py", line 236, in _step
    result = coro.send(value)
  File "feed2discord.py", line 593, in background_check_feed
    message)
  File "C:\Python34\lib\asyncio\coroutines.py", line 141, in coro
    res = func(*args, **kw)
  File "feed2discord.py", line 302, in send_message_wrapper
    actually_send_message(channel,message,delay,FEED,feed))
Traceback (most recent call last):
  File "C:\Python34\lib\asyncio\tasks.py", line 236, in _step
    result = coro.send(value)
  File "feed2discord.py", line 317, in actually_send_message
    yield from client.send_message(channel['object'],message)
  File "C:\Python34\lib\site-packages\discord.py-0.14.2-py3.4.egg\discord\client
.py", line 1096, in send_message
    data = yield from self.http.send_message(channel_id, content, guild_id=guild
_id, tts=tts)
  File "C:\Python34\lib\site-packages\discord.py-0.14.2-py3.4.egg\discord\http.p
y", line 137, in request
    raise HTTPException(r, data)
discord.errors.HTTPException: BAD REQUEST (status code: 400)
freiheit commented 8 years ago

This really looks like there's some sort of network problem between you and discordapp.com...

hakufu commented 7 years ago

I'm getting a similar error now as well. Happens around once daily. Have to restart the bot afterwards generally. Here is the crash log below:

9|saberfee | ERROR:main:/r/Saber:Unexpected error: 9|saberfee | ERROR:main:Traceback (most recent call last): 9|saberfee | File "/var/www/vhosts//bots/saber_rss/discord_feedbot/feed2discord.py", line 486, in background_check_feed 9|saberfee | raise HTTPError() 9|saberfee | File "/usr/local/lib/python3.5/dist-packages/aiohttp/web_exceptions.py", line 77, in init 9|saberfee | body=body, text=text, content_type=content_type) 9|saberfee | File "/usr/local/lib/python3.5/dist-packages/aiohttp/web_reqrep.py", line 832, in init 9|saberfee | super().init(status=status, reason=reason, headers=headers) 9|saberfee | File "/usr/local/lib/python3.5/dist-packages/aiohttp/web_reqrep.py", line 419, in init 9|saberfee | self.set_status(status, reason) 9|saberfee | File "/usr/local/lib/python3.5/dist-packages/aiohttp/web_reqrep.py", line 463, in set_status 9|saberfee | self._status = int(status) 9|saberfee | TypeError: int() argument must be a string, a bytes-like object or a number, not 'NoneType' 9|saberfee | 9|saberfee | ERROR:main:/r/Saber:giving up 9|saberfee | ERROR:asyncio:Task exception was never retrieved 9|saberfee | future: <Task finished coro=<background_check_feed() done, defined at /var/www/vhosts//bots/saber_rss/discord_feedbot/fee d2discord.py:354> exception=TypeError("int() argument must be a string, a bytes-like object or a number, not 'NoneType'",)> 9|saberfee | Traceback (most recent call last): 9|saberfee | File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step 9|saberfee | result = coro.send(None) 9|saberfee | File "/var/www/vhosts//bots/saber_rss/discord_feedbot/feed2discord.py", line 486, in background_check_feed 9|saberfee | raise HTTPError() 9|saberfee | File "/usr/local/lib/python3.5/dist-packages/aiohttp/web_exceptions.py", line 77, in init 9|saberfee | body=body, text=text, content_type=content_type) 9|saberfee | File "/usr/local/lib/python3.5/dist-packages/aiohttp/web_reqrep.py", line 832, in init 9|saberfee | super().init(status=status, reason=reason, headers=headers) 9|saberfee | File "/usr/local/lib/python3.5/dist-packages/aiohttp/web_reqrep.py", line 419, in init 9|saberfee | self.set_status(status, reason) 9|saberfee | File "/usr/local/lib/python3.5/dist-packages/aiohttp/web_reqrep.py", line 463, in set_status 9|saberfee | self._status = int(status) 9|saberfee | TypeError: int() argument must be a string, a bytes-like object or a number, not 'NoneType' 9|saberfee | /usr/local/lib/python3.5/dist-packages/aiohttp/connector.py:59: ResourceWarning: Unclosed connection Connection<('www.reddit.com', 44 3, True)> 9|saberfee | ResourceWarning) 9|saberfee | ERROR:asyncio:Unclosed connection 9|saberfee | client_connection: Connection<('www.reddit.com', 443, True)> 9|saberfee | /usr/local/lib/python3.5/dist-packages/aiohttp/client_reqrep.py:585: ResourceWarning: Unclosed response <ClientResponse(https://www.r eddit.com/r/Saber/new/.rss) [503 Service Unavailable]> 9|saberfee | <CIMultiDictProxy('Content-Type': 'text/html; charset=UTF-8', 'Fastly-Restarts': '1', 'Content-Length': '469', 'Accept-Ranges': 'byte s', 'Date': 'Thu, 23 Mar 2017 16:23:13 GMT', 'Via': '1.1 varnish', 'Connection': 'keep-alive', 'X-Served-By': 'cache-ord1733-ORD', 'X-Cache': 'MIS S', 'X-Cache-Hits': '0', 'X-Timer': 'S1490286183.920317,VS0,VE10041', 'Cache-Control': 'private, max-age=3600', 'Server': 'snooserv')> 9|saberfee | 9|saberfee | ResourceWarning) 9|saberfee | ERROR:asyncio:Unclosed response 9|saberfee | client_response: <ClientResponse(https://www.reddit.com/r/Saber/new/.rss) [503 Service Unavailable]> 9|saberfee | <CIMultiDictProxy('Content-Type': 'text/html; charset=UTF-8', 'Fastly-Restarts': '1', 'Content-Length': '469', 'Accept-Ranges': 'byte s', 'Date': 'Thu, 23 Mar 2017 16:23:13 GMT', 'Via': '1.1 varnish', 'Connection': 'keep-alive', 'X-Served-By': 'cache-ord1733-ORD', 'X-Cache': 'MIS S', 'X-Cache-Hits': '0', 'X-Timer': 'S1490286183.920317,VS0,VE10041', 'Cache-Control': 'private, max-age=3600', 'Server': 'snooserv')> 9|saberfee |

freiheit commented 7 years ago

Looks like maybe the bot isn't handling a 503 error from Reddit very well...

I've pushed a change (master branch) that might help it survive this better. Hard to test.

Also, how often are you checking that reddit feed? How many reddit feeds are you checking? I've noticed that they'll do temporary blocks if you hit them too often.

hakufu commented 7 years ago

Thanks I'll test it out. It checks around every 30-60s. I changed that to a longer period. min 60 now as well. (noticed I left the min time to 1s) In the past I used a modified Awesomebot(set to 60s intervals) and it still isn't blocked but is extremely outdated.

freiheit commented 7 years ago

I've got 5 minutes as the minimum I'll use with reddit... I did have one feed checking every 60s (and well as a few other feeds with longer times) and was getting those 503 errors after the bot ran for a while. I think to hit the problem you have to sustain a high check rate for a while.

If you're seeing it daily, you might be just right at the threshold for daily rss checks or something...

hakufu commented 7 years ago

Yeah I'd prefer a longer wait time too but server owner wants it checked every 60s to match the old one.. is what it is lol. Thanks for responding man. I appreciate it.