Connections fail due to getaddrinfo() timeouts

[weedy]

After a series of reconnects my bot was only connected to half it's normal networks. Forcing the reconnect with @disconnect then @connect resulted in the bot dying.

DEBUG 2013-09-24T15:43:26 Incoming message (wsynet): :mimir.eigenstate.org 372 ph34r :-
DEBUG 2013-09-24T15:43:26 Incoming message (wsynet): :mimir.eigenstate.org 372 ph34r :-   This server is a node of the Uruchai IRC network. The following
INFO 2013-09-24T15:43:26 Removing driver SocketDriver(Irc object for wsynet).
ERROR 2013-09-24T15:43:26 Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 108, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 194, in run
    self._select()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 170, in _select
    instance._read()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 233, in _read
    self.irc.feedMsg(msg)
AttributeError: 'NoneType' object has no attribute 'feedMsg'
ERROR 2013-09-24T15:43:26 Exception id: 0xd6d3a
DEBUG 2013-09-24T15:43:26 Supybot version: 0.83.4.1+limnoria 2013-08-22T14:03:37+0200

Locals by frame, innermost last:

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py at line 110
                      driver = <supybot.drivers.Socket.SocketDriver object at 0xbe3426c>
                        name = 'SocketDriver(Irc object for rizon)'

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 194
                        self = <supybot.drivers.Socket.SocketDriver object at 0xbe3426c>
                         now = 1380051806.583078

Frame _select in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 176
                       rlist = [<socket._socketobject object at 0xc2e8bc4>, <socket._socketobject object at 0xc2e8bc4>]
                       xlist = []
                    instance = <supybot.drivers.Socket.SocketDriver object at 0x87aceec>
                        inst = <supybot.drivers.Socket.SocketDriver object at 0x87aceec>
                           x = <supybot.drivers.Socket.SocketDriver object at 0x87aceec>
                       wlist = []
                         cls = <class 'supybot.drivers.Socket.SocketDriver'>

Frame _read in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 244
                         msg = IrcMsg(prefix="mimir.eigenstate.org", command="372", args=('ph34r', '-   rules apply to all users including operators unless otherwise'))
                        line = ':mimir.eigenstate.org 372 ph34r :-   rules apply to all users including operators unless otherwise\r'
                       lines = [':mimir.eigenstate.org 372 ph34r :-   rules apply to all users including operators unless otherwise\r', ':mimir.eigenstate.org 372 ph34r :-   specified:\r', ':mimir.eigenstate.org 372 ph34r :- \r', ':mimir.eigenstate.org 372 ph34r :-   1. Bots are allowed as long as they do not:\r', ':mimir.eigenstate.org 372 ph34r :- \r', ':mimir.eigenstate.org 372 ph34r :-      * ...spam channels or users (directly or indirectly).\r', ':mimir.eigenstate.org 372 ph34r :- \r', ':mimir.eigenstate.org 372 ph34r :-      * ...attempt to take over channels, crack nickname passwords or\r', ':mimir.eigenstate.org 372 ph34r :-        otherwise attempt to exploit services in abusive ways.\r', ':mimir.eigenstate.org 372 ph34r :- \r', ':mimir.eigenstate.org 372 ph34r :-      * ...participate in malware bot networks. This should go with-\r', ':mimir.eigenstate.org 372 ph34r :-        out saying.\r', ':mimir.eigenstate.org 372 ph34r :- \r', ':mimir.eigenstate.org 372 ph34r :-      In short: use your best judgement.\r', ':mimir.eigenstate.org 372 ph34r :- \r']
                        self = <supybot.drivers.Socket.SocketDriver object at 0x87aceec>

+-----------------------+
| End of locals display |
+-----------------------+

ERROR 2013-09-24T15:43:26 Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 108, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 194, in run
    self._select()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 170, in _select
    instance._read()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 233, in _read
    self.irc.feedMsg(msg)
AttributeError: 'NoneType' object has no attribute 'feedMsg'
ERROR 2013-09-24T15:43:26 Exception id: 0xd6d3a
DEBUG 2013-09-24T15:43:26 Supybot version: 0.83.4.1+limnoria 2013-08-22T14:03:37+0200

Locals by frame, innermost last:

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py at line 110
                      driver = <supybot.drivers.Socket.SocketDriver object at 0x88b0a4c>
                        name = 'SocketDriver(Irc object for irchighway)'

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 194
                        self = <supybot.drivers.Socket.SocketDriver object at 0x88b0a4c>
                         now = 1380051806.589318

Frame _select in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 176
                       rlist = [<socket._socketobject object at 0xc2e8bc4>, <socket._socketobject object at 0xc2e8bc4>]
                       xlist = []
                    instance = <supybot.drivers.Socket.SocketDriver object at 0x87aceec>
                        inst = <supybot.drivers.Socket.SocketDriver object at 0x87aceec>
                           x = <supybot.drivers.Socket.SocketDriver object at 0x87aceec>
                       wlist = []
                         cls = <class 'supybot.drivers.Socket.SocketDriver'>

Frame _read in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 244
                         msg = IrcMsg(prefix="mimir.eigenstate.org", command="372", args=('ph34r', '-   2. Report all offensive behavior by all users (human or otherwise)'))
                        line = ':mimir.eigenstate.org 372 ph34r :-   2. Report all offensive behavior by all users (human or otherwise)\r'
                       lines = [':mimir.eigenstate.org 372 ph34r :-   2. Report all offensive behavior by all users (human or otherwise)\r', ':mimir.eigenstate.org 372 ph34r :-      to an operator immediately.\r', ':mimir.eigenstate.org 372 ph34r :- \r', ':mimir.eigenstate.org 372 ph34r :-   3. If you would like to contest disciplinary action administered by\r', ':mimir.eigenstate.org 372 ph34r :-      an operator, please contact an operator at one of the addresses\r', ':mimir.eigenstate.org 372 ph34r :-      provided below.\r', ':mimir.eigenstate.org 372 ph34r :- \r', ':mimir.eigenstate.org 372 ph34r :-   4. We ask that you not attempt to dodge bans using proxies. If you\r', ":mimir.eigenstate.org 372 ph34r :-      do and we catch you, then we'll have to block the proxy which\r", ':mimir.eigenstate.org 372 ph34r :-      may deprive legitimate users of access to this server.\r', ':mimir.eigenstate.org 372 ph34r :- \r', ':mimir.eigenstate.org 372 ph34r :-   5. The operators below are the *only* operators. If you come across\r', ':mimir.eigenstate.org 372 ph34r :-      anyone else claiming they are an operator, please report it to\r']
                        self = <supybot.drivers.Socket.SocketDriver object at 0x87aceec>

+-----------------------+
| End of locals display |
+-----------------------+

INFO 2013-09-24T15:43:26 Removing driver SocketDriver(Irc object for rizon).
INFO 2013-09-24T15:43:26 Removing driver SocketDriver(Irc object for irchighway).
ERROR 2013-09-24T15:43:26 Schedule is the only remaining driver, why do we continue to live?

[weedy]

Still dying, different error. If it could reset itself better that would be nice. It's annoying to come home and find it fell off one or more networks because of stuck disconnections.

WARNING 2014-02-26T10:28:51 Disconnect from irc.sxci.net:9999: error: [Errno 104] Connection reset by peer.
INFO 2014-02-26T10:28:51 Reconnecting to rizon at 2014-02-26T10:29:01.
DEBUG 2014-02-26T10:29:02 Resetting Irc object for rizon.
INFO 2014-02-26T10:29:02 Connecting to irc.splitnet.net:9999.
WARNING 2014-02-26T10:29:12 Error connecting to irc.splitnet.net:9999: timeout: timed out
INFO 2014-02-26T10:29:12 Reconnecting to rizon at 2014-02-26T10:29:22.
DEBUG 2014-02-26T10:29:14 Outgoing message (WSynet): PING :1393428554
DEBUG 2014-02-26T10:29:25 Resetting Irc object for rizon.
INFO 2014-02-26T10:29:25 Connecting to irc.rizon.net:9999.
ERROR 2014-02-26T10:29:25 Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 105, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 185, in run
    self.reconnect()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 295, in reconnect
    self.conn = utils.net.getSocket(address, socks_proxy)
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py", line 56, in getSocket
    addrinfo = socket.getaddrinfo(host, None)
TypeError: getaddrinfo() argument 1 must be string or None
ERROR 2014-02-26T10:29:25 Exception id: 0x73c51
DEBUG 2014-02-26T10:29:25 Supybot version: 0.83.4.1+limnoria 2014-02-21T00-24-58

[progval]

Could you add print(repr(host)) before line 56 in src/utils/net.py, and then, next time you get such an error, there would be line before the traceback that would help me guess where the bug comes from

On 26/02/2014 16:37, weedy wrote:

Still dying, different error. If it could reset itself better that would be nice. It's annoying to come home and find it fell off one or more networks because of stuck disconnections.

WARNING 2014-02-26T10:28:51 Disconnect from irc.sxci.net:9999: error: [Errno 104] Connection reset by peer.
INFO 2014-02-26T10:28:51 Reconnecting to rizon at 2014-02-26T10:29:01.
DEBUG 2014-02-26T10:29:02 Resetting Irc object for rizon.
INFO 2014-02-26T10:29:02 Connecting to irc.splitnet.net:9999.
WARNING 2014-02-26T10:29:12 Error connecting to irc.splitnet.net:9999: timeout: timed out
INFO 2014-02-26T10:29:12 Reconnecting to rizon at 2014-02-26T10:29:22.
DEBUG 2014-02-26T10:29:14 Outgoing message (WSynet): PING :1393428554
DEBUG 2014-02-26T10:29:25 Resetting Irc object for rizon.
INFO 2014-02-26T10:29:25 Connecting to irc.rizon.net:9999.
ERROR 2014-02-26T10:29:25 Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 105, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 185, in run
    self.reconnect()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 295, in reconnect
    self.conn = utils.net.getSocket(address, socks_proxy)
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py", line 56, in getSocket
    addrinfo = socket.getaddrinfo(host, None)
TypeError: getaddrinfo() argument 1 must be string or None
ERROR 2014-02-26T10:29:25 Exception id: 0x73c51
DEBUG 2014-02-26T10:29:25 Supybot version: 0.83.4.1+limnoria 2014-02-21T00-24-58

---

Reply to this email directly or view it on GitHub: https://github.com/ProgVal/Limnoria/issues/513#issuecomment-36137847

[Mikaela]

Does this still happen?

[weedy]

Every day.

[Mikaela]

Did you do what @ProgVal asked? I haven't heard anyone else saying that this happens.

[progval]

Or you could enable DEBUG log level and send me the log, it will probably be more helpful. (Careful, there might be a password in the log)

[weedy]

I'm still trying to catch error 0xd6d3a and 0x87be8 in my logs.

DEBUG 2014-07-26T01:27:01 supybot Resetting Irc object for WSynet.
DEBUG 2014-07-26T01:27:01 supybot WSynet: Queuing NICK command, nick is ph34r.
DEBUG 2014-07-26T01:27:01 supybot WSynet: Queuing USER command, ident is ph34r, user is ph34r.
INFO 2014-07-26T01:27:01 supybot Connecting to irc.wsyntax.com:6667.
ERROR 2014-07-26T01:27:01 supybot Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 105, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 185, in run
    self.reconnect()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 297, in reconnect
    socks_proxy=socks_proxy)
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py", line 57, in getSocket
    addrinfo = socket.getaddrinfo(host, port)
TypeError: getaddrinfo() argument 1 must be string or None
ERROR 2014-07-26T01:27:02 supybot Exception id: 0x73c51
DEBUG 2014-07-26T01:27:02 supybot Supybot version: 0.83.4.1+limnoria 2014.06.26

Locals by frame, innermost last:

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py at line 107
                      driver = <supybot.drivers.Socket.SocketDriver object at 0x986764c>
                        name = 'SocketDriver(Irc object for WSynet)'

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 185
              self.outbuffer = 'PING :1406352410\r\n'
                self.servers = []
        self.nextReconnectTime = None
                   self.conn = <socket._socketobject object at 0xd2a3f7c>
         self.writeCheckTime = None
                        self = <supybot.drivers.Socket.SocketDriver object at 0x986764c>
                self.eagains = 0
               self.inbuffer = ''
           self.currentDelay = 10.0
           self.networkGroup = <supybot.registry.Group object at 0x964e30c>
               self._attempt = 2
          self.currentServer = 'irc.wsyntax.com:6667'
                 self.zombie = False
                         now = 1406352421.866241
                    self.irc = <irclib.Irc object for WSynet>
              self.connected = False
Frame reconnect in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 301
              self.outbuffer = 'PING :1406352410\r\n'
                self.eagains = 0
                 self.zombie = False
                    self.irc = <irclib.Irc object for WSynet>
                        port = 6667
         self.writeCheckTime = None
                        self = <supybot.drivers.Socket.SocketDriver object at 0x986764c>
               self.inbuffer = ''
                        wait = False
                self.servers = []
                    resolver = None
                     address = 10
          self.currentServer = 'irc.wsyntax.com:6667'
                 socks_proxy = ''
                   self.conn = <socket._socketobject object at 0xd2a3f7c>
                       reset = True
        self.nextReconnectTime = None
                      server = ('irc.wsyntax.com', 6667)
           self.currentDelay = 10.0
           self.networkGroup = <supybot.registry.Group object at 0x964e30c>
               self._attempt = 2
              self.connected = False

Frame getSocket in /home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py at line 57
                        host = 10
                       vhost = None
                 socks_proxy = ''
                        port = 6667
                     vhostv6 = None

+-----------------------+
| End of locals display |
+-----------------------+

INFO 2014-07-26T01:27:02 supybot Removing driver SocketDriver(Irc object for WSynet).

ERROR 2014-07-26T02:47:43 supybot Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 105, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 185, in run
    self.reconnect()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 288, in reconnect
    attempt=self._attempt)
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py", line 44, in getAddressFromHostname
    addrinfo = socket.getaddrinfo(host, port)
error: [Errno 110] Connection timed out
ERROR 2014-07-26T02:47:43 supybot Exception id: 0xf5f20
DEBUG 2014-07-26T02:47:43 supybot Supybot version: 0.83.4.1+limnoria 2014.06.26

Locals by frame, innermost last:

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py at line 107
                      driver = <supybot.drivers.Socket.SocketDriver object at 0xd0b2a8c>
                        name = 'SocketDriver(Irc object for Rizon)'

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 185
              self.outbuffer = ''
                self.servers = []
        self.nextReconnectTime = None
                   self.conn = <ssl.SSLSocket object at 0xd162aac>
         self.writeCheckTime = None
                        self = <supybot.drivers.Socket.SocketDriver object at 0xd0b2a8c>
                self.eagains = 0
               self.inbuffer = ''
           self.currentDelay = 10.0
           self.networkGroup = <supybot.registry.Group object at 0x9610f8c>
               self._attempt = 140
          self.currentServer = 'irc.splitnet.net:9999'
                 self.zombie = False
                         now = 1406357243.806692
                    self.irc = <irclib.Irc object for Rizon>
              self.connected = False

Frame reconnect in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 292
                       reset = True
              self.outbuffer = ''
        self.nextReconnectTime = None
                   self.conn = <ssl.SSLSocket object at 0xd162aac>
           self.networkGroup = <supybot.registry.Group object at 0x9610f8c>
                    self.irc = <irclib.Irc object for Rizon>
         self.writeCheckTime = None
               self._attempt = 140
                        self = <supybot.drivers.Socket.SocketDriver object at 0xd0b2a8c>
                self.eagains = 0
                      server = ('irc.splitnet.net', 9999)
                self.servers = []
           self.currentDelay = 10.0
                    resolver = None
                 self.zombie = False
          self.currentServer = 'irc.splitnet.net:9999'
                 socks_proxy = ''
              self.connected = False
               self.inbuffer = ''
                        wait = False

Frame getAddressFromHostname in /home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py at line 44
                        host = 'irc.splitnet.net'
                     attempt = 140
                        port = None

+-----------------------+
| End of locals display |
+-----------------------+

DEBUG 2014-07-26T02:47:43 supybot Resetting Irc object for irchighway.

INFO 2014-07-26T02:53:35 supybot Reconnecting to freenode at 2014-07-26T02:53:45.
DEBUG 2014-07-26T02:53:45 supybot Resetting Irc object for freenode.
ERROR 2014-07-26T02:54:05 supybot Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 105, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 185, in run
    self.reconnect()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 288, in reconnect
    attempt=self._attempt)
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py", line 44, in getAddressFromHostname
    addrinfo = socket.getaddrinfo(host, port)
error: [Errno 110] Connection timed out
ERROR 2014-07-26T02:54:05 supybot Exception id: 0xf5f20
DEBUG 2014-07-26T02:54:05 supybot Supybot version: 0.83.4.1+limnoria 2014.06.26

Locals by frame, innermost last:

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py at line 107
                      driver = <supybot.drivers.Socket.SocketDriver object at 0xd22898c>
                        name = 'SocketDriver(Irc object for freenode)'

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 185
              self.outbuffer = ''
                self.servers = [('irc.freenode.net', 7000), ('chat.freenode.net', 7000)]
        self.nextReconnectTime = None
                   self.conn = <ssl.SSLSocket object at 0xd2b0d84>
         self.writeCheckTime = None
                        self = <supybot.drivers.Socket.SocketDriver object at 0xd22898c>
                self.eagains = 0
               self.inbuffer = ''
           self.currentDelay = 10.0
           self.networkGroup = <supybot.registry.Group object at 0x961e3ac>
               self._attempt = 169
          self.currentServer = 'dickson.freenode.net:7000'
                 self.zombie = False
                         now = 1406357625.968859
                    self.irc = <irclib.Irc object for freenode>
              self.connected = False

Frame reconnect in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 292
                       reset = True
              self.outbuffer = ''
        self.nextReconnectTime = None
                   self.conn = <ssl.SSLSocket object at 0xd2b0d84>
           self.networkGroup = <supybot.registry.Group object at 0x961e3ac>
                    self.irc = <irclib.Irc object for freenode>
         self.writeCheckTime = None
               self._attempt = 169
                        self = <supybot.drivers.Socket.SocketDriver object at 0xd22898c>
                self.eagains = 0
                      server = ('dickson.freenode.net', 7000)
                self.servers = [('irc.freenode.net', 7000), ('chat.freenode.net', 7000)]
           self.currentDelay = 10.0
                    resolver = None
                 self.zombie = False
          self.currentServer = 'dickson.freenode.net:7000'
                 socks_proxy = ''
              self.connected = False
               self.inbuffer = ''
                        wait = False

Frame getAddressFromHostname in /home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py at line 44
                        host = 'dickson.freenode.net'
                     attempt = 169
                        port = None

+-----------------------+
| End of locals display |
+-----------------------+

INFO 2014-07-26T02:54:05 supybot Removing driver SocketDriver(Irc object for freenode).
ERROR 2014-07-26T02:54:06 supybot Schedule is the only remaining driver, why do we continue to live?
ERROR 2014-07-26T02:54:07 supybot Schedule is the only remaining driver, why do we continue to live?
ERROR 2014-07-26T02:54:08 supybot Schedule is the only remaining driver, why do we continue to live?
ERROR 2014-07-26T02:54:09 supybot Schedule is the only remaining driver, why do we continue to live?
ERROR 2014-07-26T02:54:10 supybot Schedule is the only remaining driver, why do we continue to live?
ERROR 2014-07-26T02:54:11 supybot Schedule is the only remaining driver, why do we continue to live?

[weedy]

ERROR 2014-08-14T02:26:46 supybot Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 105, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 185, in run
    self.reconnect()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 288, in reconnect
    attempt=self._attempt)
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py", line 44, in getAddressFromHostname
    addrinfo = socket.getaddrinfo(host, port)
error: [Errno 110] Connection timed out
ERROR 2014-08-14T02:26:46 supybot Exception id: 0xf5f20
DEBUG 2014-08-14T02:26:46 supybot Supybot version: 0.83.4.1+limnoria 2014.06.26

Locals by frame, innermost last:

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py at line 107
                      driver = <supybot.drivers.Socket.SocketDriver object at 0x8cf3a8c>
                        name = 'SocketDriver(Irc object for irchighway)'

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 185
              self.outbuffer = ''
                self.servers = [('genesis.us.irchighway.net', 9999), ('labyrinth.us.irchighway.net', 9999)]
        self.nextReconnectTime = None
                   self.conn = <ssl.SSLSocket object at 0x8c222cc>
         self.writeCheckTime = None
                        self = <supybot.drivers.Socket.SocketDriver object at 0x8cf3a8c>
                self.eagains = 0
               self.inbuffer = ''
           self.currentDelay = 10.0
           self.networkGroup = <supybot.registry.Group object at 0x894a06c>
               self._attempt = 73
          self.currentServer = 'friedchicken.co.us.irchighway.net:9999'
                 self.zombie = False
                         now = 1407997586.683279
                    self.irc = <irclib.Irc object for irchighway>
              self.connected = False

Frame reconnect in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 292
                       reset = True
              self.outbuffer = ''
        self.nextReconnectTime = None
                   self.conn = <ssl.SSLSocket object at 0x8c222cc>
           self.networkGroup = <supybot.registry.Group object at 0x894a06c>
                    self.irc = <irclib.Irc object for irchighway>
         self.writeCheckTime = None
               self._attempt = 73
                        self = <supybot.drivers.Socket.SocketDriver object at 0x8cf3a8c>
                self.eagains = 0
                      server = ('friedchicken.co.us.irchighway.net', 9999)
                self.servers = [('genesis.us.irchighway.net', 9999), ('labyrinth.us.irchighway.net', 9999)]
           self.currentDelay = 10.0
                    resolver = None
                 self.zombie = False
          self.currentServer = 'friedchicken.co.us.irchighway.net:9999'
                 socks_proxy = ''
              self.connected = False
               self.inbuffer = ''
                        wait = False

Frame getAddressFromHostname in /home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py at line 44
                        host = 'friedchicken.co.us.irchighway.net'
                     attempt = 73
                        port = None

+-----------------------+
| End of locals display |
+-----------------------+

[progval]

Er… I just noticed that the error happens when doing name resolution. Could you have any issue with your DNS resolver?

[progval]

I reproduced the call to the function that errors with the exact same arguments, it works for me. Could you try running this command on the same environment as the one running the bot?

python -c "print(__import__('supybot.utils').utils.net.getAddressFromHostname('friedchicken.co.us.irchighway.net', port=None, attempt=73))"

[weedy]

Command runs fine and resolves an IP.

The bot disconnects when my internet goes down. Are you saying the DNS resolver is supposed to cause tracebacks are lock up the bot just because I lose internet for 5 minutes?

[progval]

When the bot reconnects, it uses Python's standard lib for making a DNS request. As the standard lib uses C code for that, there is no way to make it not freeze.

But if it freezes that long, there is probably an issue with your system. If your connection goes up and down, then it's normal that DNS requests are blocked. You should try installing a DNS cache server on your computer/local network.

On 14/08/2014 21:35, weedy wrote:

Command runs fine and resolves an IP.

The bot disconnects when my internet goes down. Are you saying the DNS resolver is supposed to cause tracebacks are lock up the bot just because I lose internet for 5 minutes?

---

Reply to this email directly or view it on GitHub: https://github.com/ProgVal/Limnoria/issues/513#issuecomment-52232410

[Mikaela]

You should try installing a DNS cache server on your computer/local network.

I usually have dnsmasq installed on all computers. Just set it as primary DNS server and it should work.

[weedy]

The problem isn't that DNS falls. The problem is the tracebacks kills reconnects and leaves "ghost" connections around. I'll try are get a dump the next time I have to force a reconnect.

Also I use OpenWRT, it already runs dnsmasq. None of this matters if the TTL on load balancing domains is like 5 minutes or less.

[progval]

indeed

[progval]

Can you try this?

diff --git a/src/drivers/Socket.py b/src/drivers/Socket.py
index 9a5ba7d..ddd70fb 100644
--- a/src/drivers/Socket.py
+++ b/src/drivers/Socket.py
@@ -286,7 +286,7 @@ class SocketDriver(drivers.IrcDriver, drivers.ServersMixin):
             try:
                 address = utils.net.getAddressFromHostname(server[0],
                         attempt=self._attempt)
-            except socket.gaierror as e:
+            except (socket.gaierror, socket.error) as e:
                 drivers.log.connectError(self.currentServer, e)
                 self.scheduleReconnect()
                 return

[weedy]

Thu May 26 00:44:03 2016 daemon.notice pppd[9991]: Modem hangup
Thu May 26 00:44:04 2016 daemon.notice netifd: Interface 'wan' is now down
Thu May 26 00:44:04 2016 daemon.notice netifd: Interface 'wan' is setting up now
...
Thu May 26 00:44:07 2016 daemon.notice netifd: Network device 'pppoe-wan' link is up
Thu May 26 00:44:07 2016 daemon.notice netifd: Interface 'wan' is now up
Thu May 26 00:44:07 2016 daemon.debug pppd[14360]: Script /lib/netifd/ppp-up finished (pid 14420), status = 0x0

DEBUG 2016-05-26T00:45:55 Resetting Irc object for Freenode.
DEBUG 2016-05-26T00:45:55 Freenode: Sending NICK command, nick is ph34r.
DEBUG 2016-05-26T00:45:55 Freenode: Sending USER command, ident is ph34r, user is ph34r.
INFO 2016-05-26T00:45:55 Connecting to dickson.freenode.net:7000.
ERROR 2016-05-26T00:45:55 Uncaught exception in in drivers.run:
Traceback (most recent call last):
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py", line 104, in run
    driver.run()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 179, in run
    self.reconnect()
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py", line 267, in reconnect
    vhostv6=conf.supybot.protocols.irc.vhostv6(),
  File "/home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py", line 58, in getSocket
    addrinfo = socket.getaddrinfo(host, port)
TypeError: getaddrinfo() argument 1 must be string or None
ERROR 2016-05-26T00:45:55 Exception id: 0x73c51
DEBUG 2016-05-26T00:45:55 Limnoria version: 2016.05.06

Locals by frame, innermost last:

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/__init__.py at line 106
                      driver = <supybot.drivers.Socket.SocketDriver object at 0xb46e882c>
                        name = 'SocketDriver(Irc object for Freenode)'

Frame run in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 179
              self.outbuffer = ''
                self.servers = [('kornbluth.freenode.net', 7000), ('leguin.freenode.net', 7000), ('chat.freenode.net', 7000)]
        self.nextReconnectTime = None
                   self.conn = <ssl.SSLSocket object at 0xb45f86bc>
         self.writeCheckTime = None
                        self = <supybot.drivers.Socket.SocketDriver object at 0xb46e882c>
                self.eagains = 0
                    self.ssl = True
               self.inbuffer = ''
           self.currentDelay = 10.0
           self.networkGroup = <supybot.registry.Group object at 0xb6c38e4c>
               self._attempt = 1
          self.currentServer = 'dickson.freenode.net:7000'
                 self.zombie = False
                         now = 1464237955.015497
                    self.irc = <irclib.Irc object for Freenode>
                 self.server = ('dickson.freenode.net', 7000)
              self.connected = False

Frame reconnect in /home/weedy/supybot/lib/python2.7/site-packages/supybot/drivers/Socket.py at line 272
              self.outbuffer = ''
                self.eagains = 0
               self.inbuffer = ''
                 self.zombie = False
                    self.irc = <irclib.Irc object for Freenode>
                        port = 7000
         self.writeCheckTime = None
                        self = <supybot.drivers.Socket.SocketDriver object at 0xb46e882c>
                    self.ssl = True
              network_config = <supybot.registry.Group object at 0xb6c38e4c>
                        wait = False
                self.servers = [('kornbluth.freenode.net', 7000), ('leguin.freenode.net', 7000), ('chat.freenode.net', 7000)]
                     address = 10
          self.currentServer = 'dickson.freenode.net:7000'
                 socks_proxy = ''
                 self.server = ('dickson.freenode.net', 7000)
                   self.conn = <ssl.SSLSocket object at 0xb45f86bc>
                       reset = True
        self.nextReconnectTime = None
           self.currentDelay = 10.0
           self.networkGroup = <supybot.registry.Group object at 0xb6c38e4c>
               self._attempt = 1
              self.connected = False

Frame getSocket in /home/weedy/supybot/lib/python2.7/site-packages/supybot/utils/net.py at line 58
                        host = 10
                       vhost = ''
                 socks_proxy = ''
                        port = 7000
                     vhostv6 = ''

+-----------------------+
| End of locals display |
+-----------------------+

INFO 2016-05-26T00:45:58 Removing driver SocketDriver(Irc object for Freenode).

At this point irssi and the other networks my bot is on have already reconnected. I have ipv6 disabled on this box.

[progval]

It looks like you did not restart the bot after the last update, which makes the error log hard to read.

Could you restart it, and give me the equivalent log after the update?

[weedy]

It has been restarted many times. I'm on testing from around May 10th

You included your fix already https://github.com/ProgVal/Limnoria/blob/testing/src/drivers/Socket.py#L257

[progval]

What is the result of this command?

python -c "import supybot.utils, socket; print([sockaddr[0] for (family, socktype, proto, canonname, sockaddr) in socket.getaddrinfo('dickson.freenode.net', None)])"

[weedy]

$ PYTHONPATH="lib/python2.7:lib/python2.7/site-packages" python -c "import supybot.utils, socket; print([sockaddr[0] for (family, socktype, proto, canonname, sockaddr) in socket.getaddrinfo('dickson.freenode.net', None)])"
['208.80.155.68', '208.80.155.68', '208.80.155.68', 10, 10, 10]

kill WAN

$ PYTHONPATH="lib/python2.7:lib/python2.7/site-packages" python -c "import supybot.utils, socket; print([sockaddr[0] for (family, socktype, proto, canonname, sockaddr) in socket.getaddrinfo('irc.freenode.net', None)])"
Traceback (most recent call last):
  File "<string>", line 1, in <module>
socket.error: [Errno 0] Error

After WAN comes back online

$ PYTHONPATH="lib/python2.7:lib/python2.7/site-packages" python -c "import supybot.utils, socket; print([sockaddr[0] for (family, socktype, proto, canonname, sockaddr) in socket.getaddrinfo('irc.freenode.net', None)])"
['130.185.232.126', '130.185.232.126', '130.185.232.126', '192.186.157.43', '192.186.157.43', '192.186.157.43', '193.10.255.100', '193.10.255.100', '193.10.255.100', '64.32.24.178', '64.32.24.178', '64.32.24.178', '195.148.124.79', '195.148.124.79', '195.148.124.79', '195.154.200.232', '195.154.200.232', '195.154.200.232', '185.30.166.38', '185.30.166.38', '185.30.166.38', '164.132.77.237', '164.132.77.237', '164.132.77.237', '174.143.119.91', '174.143.119.91', '174.143.119.91', '162.213.39.42', '162.213.39.42', '162.213.39.42', '130.239.18.119', '130.239.18.119', '130.239.18.119', '91.217.189.42', '91.217.189.42', '91.217.189.42', '38.229.70.22', '38.229.70.22', '38.229.70.22', '193.219.128.49', '193.219.128.49', '193.219.128.49', '185.30.166.37', '185.30.166.37', '185.30.166.37', 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10]

[progval]

what about this?

python -c "import socket; print(socket.getaddrinfo('dickson.freenode.net', None))"

[weedy]

[(2, 1, 6, '', ('208.80.155.68', 0)), (2, 2, 17, '', ('208.80.155.68', 0)), (2, 3, 0, '', ('208.80.155.68', 0)), (10, 1, 6, '', (10, '\x00\x00\x00\x00\x00\x00& \x00\x00\x08a\x02\x02')), (10, 2, 17, '', (10, '\x00\x00\x00\x00\x00\x00& \x00\x00\x08a\x02\x02')), (10, 3, 0, '', (10, '\x00\x00\x00\x00\x00\x00& \x00\x00\x08a\x02\x02'))]

[progval]

Woah, are you sure your install of Python and your libc are not corrupted?

[progval]

I asked the question here, if you want to follow it: https://stackoverflow.com/q/37816156/539465

Additionally, could you give me the results of the following command?

dig +short dickson.freenode.net AAAA

[progval]

What are your OS and its version?

[weedy]

# dig +short dickson.freenode.net AAAA
2620:0:861:202:208:80:155:68
# dig +short dickson.freenode.net A
208.80.155.68

# dig +short google.ca AAAA
2607:f8b0:400b:806::2003
# dig +short google.ca A
172.217.3.131

# cat /etc/*release
Gentoo Base System release 2.2
NAME=Gentoo
ID=gentoo
PRETTY_NAME="Gentoo/Linux"
# uname -r
4.4.0-zen+