Running bugwarrior-pull while no internet connection results in closing all tasks

[fmauch]

When running bugwarrior-pull without an active internet connection (e.g. you have a cronjob for that and you are sitting in a German train with very unreliable internet connection) it can happen, that almost all tasks get marked completed. Note, that this is not necessarily related to #896 as I experienced this also with #896 applied and I also experience this for github-related tasks.

There is an error output such as

INFO:bugwarrior.services:Working on [github_my_repos]
DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): api.github.com:443
ERROR:bugwarrior.services:Worker for [github_my_repos] failed: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /user/repos?per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f6e73c36250>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))
Traceback (most recent call last):
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/util/connection.py", line 72, in create_connection
    for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
  File "/usr/lib/python3.8/socket.py", line 918, in getaddrinfo
    for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
socket.gaierror: [Errno -3] Temporary failure in name resolution

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 703, in urlopen
    httplib_response = self._make_request(
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 386, in _make_request
    self._validate_conn(conn)
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 1040, in _validate_conn
    conn.connect()
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connection.py", line 358, in connect
    conn = self._new_conn()
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x7f6e73c36250>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 785, in urlopen
    retries = retries.increment(
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /user/repos?per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f6e73c36250>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/__init__.py", line 450, in _aggregate_issues
    for issue in service.issues():
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/github.py", line 450, in issues
    all_repos = self.client.get_repos(self.config.username)
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/github.py", line 76, in get_repos
    user_repos = self._getter(self._api_url("/user/repos?per_page=100"))
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/github.py", line 126, in _getter
    response = self.session.get(link['next'], **kwargs)
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/sessions.py", line 555, in get
    return self.request('GET', url, **kwargs)
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/sessions.py", line 542, in request
    resp = self.send(prep, **send_kwargs)
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/sessions.py", line 655, in send
    r = adapter.send(request, **kwargs)
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /user/repos?per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f6e73c36250>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))
INFO:bugwarrior.services:Done with [github_my_repos] in 0.006323s
[...]
DEBUG:bugwarrior.db:Closing tasks for succeeding services: [..., 'github_my_repos'].

So, the task seems to be marked succeeded, which seems wrong. I'm stopping debugging this for now, but I will come back to this.

[ryneeverett]

Seems like the bug is somewhere in services/__init__.py:aggregate_issues. We hit the line log.exception("Worker for [%s] failed: %s" % (target, e)) but then somehow miss the line log.exception(f"Aborted {target} due to critical error."

You're getting this error on the latest develop branch, right?

[fmauch]

technically, I think I was on #887 when testing, so 570f4edaaab74e2e882b7169f146888359cd4b46 would probably be most accurate.

[srl295]

dup of #866 (with some analysis)

[ryneeverett]

It seems probable that this is a regression introduced by #825.

[ryneeverett]

I wouldn't call this a duplicate of #866. In #866 the service failed but here the service succeeds.

[ryneeverett]

I cannot reproduce either issue. I get:

$ bugwarrior pull
INFO:bugwarrior.db:Service-defined UDAs exist: you can optionally use the `bugwarrior-uda` command to export a list of UDAs you can add to your taskrc file.
INFO:bugwarrior.services:Starting to aggregate remote issues.
INFO:bugwarrior.services:Spawning 1 workers.
INFO:bugwarrior.services:Working on [my_github]
ERROR:bugwarrior.services:Worker for [my_github] failed: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /user/repos?per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x6575b51e31f0>: Failed to establish a new connection: [Errno 101] Network is unreachable'))
Traceback (most recent call last):
  File "/lib/python3.9/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
  File "/lib/python3.9/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/lib/python3.9/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
OSError: [Errno 101] Network is unreachable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/lib/python3.9/site-packages/urllib3/connectionpool.py", line 703, in urlopen
    httplib_response = self._make_request(
  File "/lib/python3.9/site-packages/urllib3/connectionpool.py", line 386, in _make_request
    self._validate_conn(conn)
  File "/lib/python3.9/site-packages/urllib3/connectionpool.py", line 1040, in _validate_conn
    conn.connect()
  File "/lib/python3.9/site-packages/urllib3/connection.py", line 358, in connect
    self.sock = conn = self._new_conn()
  File "/lib/python3.9/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x6575b51e31f0>: Failed to establish a new connection: [Errno 101] Network is unreachable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/lib/python3.9/site-packages/requests/adapters.py", line 440, in send
    resp = conn.urlopen(
  File "/lib/python3.9/site-packages/urllib3/connectionpool.py", line 785, in urlopen
    retries = retries.increment(
  File "/lib/python3.9/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /user/repos?per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x6575b51e31f0>: Failed to establish a new connection: [Errno 101] Network is unreachable'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/bugwarrior/bugwarrior/services/__init__.py", line 444, in _aggregate_issues
    for issue in service.issues():
  File "/home/bugwarrior/bugwarrior/services/github.py", line 484, in issues
    all_repos = self.client.get_repos(self.config.username)
  File "/home/bugwarrior/bugwarrior/services/github.py", line 97, in get_repos
    user_repos = self._getter(self._api_url("/user/repos?per_page=100"))
  File "/home/bugwarrior/bugwarrior/services/github.py", line 148, in _getter
    response = self._request(link['next'])
  File "/home/bugwarrior/bugwarrior/services/github.py", line 161, in _request
    response = self.session.get(url, **self.kwargs)
  File "/lib/python3.9/site-packages/requests/sessions.py", line 542, in get
    return self.request('GET', url, **kwargs)
  File "/lib/python3.9/site-packages/requests/sessions.py", line 529, in request
    resp = self.send(prep, **send_kwargs)
  File "/lib/python3.9/site-packages/requests/sessions.py", line 645, in send
    r = adapter.send(request, **kwargs)
  File "/lib/python3.9/site-packages/requests/adapters.py", line 519, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /user/repos?per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x6575b51e31f0>: Failed to establish a new connection: [Errno 101] Network is unreachable'))
INFO:bugwarrior.services:Done with [my_github] in 0.111364s
ERROR:bugwarrior.services:Aborted my_github due to critical error.
NoneType: None
INFO:bugwarrior.services:Done aggregating remote issues.
INFO:bugwarrior.db:Adding 0 tasks
INFO:bugwarrior.db:Updating 0 tasks
INFO:bugwarrior.db:Closing 0 tasks

The notable difference is that both your errors originated in socket.gaierror whereas mine originated in OSError. Perhaps the difference is because my machine is caching DNS and yours are not.

Edit: Even with dns turned off I still get the above stack traces.

[fmauch]

I'll give this another inspection....

[ryneeverett]

I just reproduced this (your bug and your traceback) on accident. Consistent with what you described, this seems to occur when one's system thinks it is connected to a network but actually can't get any packets through.

[ryneeverett]

I simulated network failures with netem while trying to figure this out. I inconsistently achieved a variety of buggy failures with packet loss in the 50-100% range. For future reference:

# turn on packet loss:
$ tc qdisc add dev <interface> root netem loss 75%

# turn off packet loss:
$ tc qdisc del dev <interface> root netem

The most disturbing failures I saw were in gitlab, which would sometimes succeed but still close all the issues from a subset of repos. It did not appear that bugwarrior even queried for issues from those repos, so it's almost as if the query fetching the repo list received an incomplete response but did not raise an exception.

[fmauch]

I found some spare minutes investigating the problem: My gitlab service responds with

DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): server.domain.tld:443
DEBUG:bugwarrior.services.gitlab:Found 0 issues.
DEBUG:bugwarrior.services.gitlab:Pruned down to 0 issues.
DEBUG:bugwarrior.services:Worker for [gitlab_issues] finished ok.
INFO:bugwarrior.services:Done with [gitlab_issues] in 0.09430241584777832.

When replacing the try-except block from https://github.com/ralphbean/bugwarrior/blob/09264779744d662c894fb4dc7aa7e2e57e88addf/bugwarrior/services/gitlab.py#L287-L294

with

result = self._fetch_paged(query)

I get the output

DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): server.domain.tld:443
ERROR:bugwarrior.services:Worker for [gitlab_issues] failed: HTTPSConnectionPool(host='server.domain.tld', port=443): Max retries exceeded with url: /api/v4/issues?assignee_id=175&state=opened&scope=all&page=1&per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f74e3be5700>: Failed to establish a new connection: [Errno 111] Connection refused'))
Traceback (most recent call last):
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/util/connection.py", line 95, in create_connection
    raise err
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/util/connection.py", line 85, in create_connection
    sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 703, in urlopen
    httplib_response = self._make_request(
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 386, in _make_request
    self._validate_conn(conn)
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 1040, in _validate_conn
    conn.connect()
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connection.py", line 358, in connect
    conn = self._new_conn()
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x7f74e3be5700>: Failed to establish a new connection: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/connectionpool.py", line 785, in urlopen
    retries = retries.increment(
  File "/home/mauch/.local/lib/python3.8/site-packages/urllib3/util/retry.py", line 592, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='server.domain.tld', port=443): Max retries exceeded with url: /api/v4/issues?assignee_id=175&state=opened&scope=all&page=1&per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f74e3be5700>: Failed to establish a new connection: [Errno 111] Connection refused'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/__init__.py", line 444, in _aggregate_issues
    for issue in service.issues():
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/gitlab.py", line 714, in issues
    issues = self.gitlab_client.get_issues_from_query(self.config.issue_query)
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/gitlab.py", line 290, in get_issues_from_query
    result = self._fetch_paged(query)
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/gitlab.py", line 165, in _fetch_paged
    items = self._fetch(relative_url, params=params)
  File "/home/mauch/local_install/src/bugwarrior/bugwarrior/services/gitlab.py", line 142, in _fetch
    response = requests.get(
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/api.py", line 76, in get
    return request('get', url, params=params, **kwargs)
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/api.py", line 61, in request
    return session.request(method=method, url=url, **kwargs)
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/sessions.py", line 542, in request
    resp = self.send(prep, **send_kwargs)
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/sessions.py", line 655, in send
    r = adapter.send(request, **kwargs)
  File "/home/mauch/.local/lib/python3.8/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPSConnectionPool(host='server.domain.tld', port=443): Max retries exceeded with url: /api/v4/issues?assignee_id=175&state=opened&scope=all&page=1&per_page=100 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f74e3be5700>: Failed to establish a new connection: [Errno 111] Connection refused'))
INFO:bugwarrior.services:Done with [gitlab_issues] in 0.09662151336669922.

That might be rather an edge case. As server.domain.tld seems to be in my dns cache it knows how to handle it and it tries to connect to it directly. I am suprised that I get a "connection refused", I would expect "destination host unreachable", though.

Anyway, the problem of closed issues seems to origin from get_issues_from_query catching too many exceptions and silently passing.

[ryneeverett]

Anyway, the problem of closed issues seems to origin from get_issues_from_query catching too many exceptions and silently passing.

Any idea how it's bypassing the except ConnectionError block?

[fmauch]

Any idea how it's bypassing the except ConnectionError block?

Absolutely not!

exception ConnectionError A base class for connection-related issues.

Subclasses are BrokenPipeError, ConnectionAbortedError, ConnectionRefusedError and ConnectionResetError.

A small test code

try:
    raise ConnectionRefusedError()
except ConnectionError:
    print("Got connection error")
    raise ConnectionError()
except OSError:
    print("Got OSError")

left me with an unhandled ConnectionError as I would have expected.

[ryneeverett]

Since the scope of this issue was expanded to include a gitlab-specific bug I'll reopen to track that.

[ryneeverett]

Any idea how it's bypassing the except ConnectionError block?

Absolutely not!

@fmauch I finally squinted at your traceback the right way and realized that ConnectionError != requests.exceptions.ConnectionError!