Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

If a calendar is deleted, the bot gets stuck in a tight retry loop #84

Open
nmlorg opened this issue Dec 14, 2019 · 1 comment
Open

If a calendar is deleted, the bot gets stuck in a tight retry loop #84

nmlorg opened this issue Dec 14, 2019 · 1 comment
Assignees
@nmlorg
Labels
bug Something isn't working

Comments

@nmlorg
Copy link
Owner

nmlorg commented Dec 14, 2019 

2019-12-13 20:00:04,205 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=XXX&alt=json
2019-12-13 20:00:04,261 INFO transport.py:185] Refreshing due to a 401 (attempt 1/2)
2019-12-13 20:00:04,336 INFO client.py:777] Refreshing access_token
2019-12-13 20:00:04,555 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=XXX&alt=json
2019-12-13 20:00:04,700 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=XXX&alt=json
2019-12-13 20:00:04,838 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=XXX&alt=json
2019-12-13 20:00:05,011 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40gmail.com/events?singleEvents=true&syncToken=XXX&alt=json
2019-12-13 20:00:05,172 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40gmail.com/events?singleEvents=true&syncToken=XXX&alt=json
2019-12-13 20:00:05,306 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=XXX&alt=json
2019-12-13 20:00:05,474 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=XXX&alt=json
2019-12-13 20:00:05,584 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=XXX&alt=json returned "Not Found">
2019-12-13 20:00:05,599 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json
2019-12-13 20:00:05,701 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json returned "Not Found">
2019-12-13 20:00:05,705 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json
2019-12-13 20:00:05,810 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json returned "Not Found">
2019-12-13 20:00:05,814 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json

 ...

2019-12-14 10:40:48,067 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json
2019-12-14 10:40:48,180 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json returned "Not Found">
2019-12-14 10:40:48,184 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json
2019-12-14 10:40:48,287 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json returned "Not Found">
2019-12-14 10:40:48,292 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json

For this outage, service was halted at 2019-12-13 20:00:04 and restored at 2019-12-14 11:15:42 Pacific time.

According to https://console.cloud.google.com/apis/dashboard, the bot has used 488,717 Google Calendar API calls (99% error rate) in the past 1 day and 499,042 (97% error rate) in the past 30; it's been averaging a little over 9 requests per second.

This is actually strictly a bug in metabot.calendars.google, not metabot proper:

    def poll(self):
        changes = False
        page_token = None
        while True:
            try:
                results = self.service().events().list(  # pylint: disable=no-member
                    calendarId=self.calpath,
                    singleEvents=True,
                    syncToken=self.sync_token,
                    pageToken=page_token).execute()
            except:  # pylint: disable=bare-except
                logging.exception('Error during event fetch:')
                self.sync_token = page_token = None
                self.events = {}
                continue

The bare except needs to actually hold onto the exception and check if its code is 404 (or potentially 403, or any non-500) and behave differently (for now, probably log the exception but otherwise just treat it as a successful .list() with no results).
@nmlorg nmlorg added the bug Something isn't working label Dec 14, 2019
@nmlorg nmlorg self-assigned this Dec 14, 2019
@nmlorg
Copy link
Owner Author

nmlorg commented Apr 5, 2020

Another calendar was deleted out from under the bot today, causing another outage.

2020-04-04 12:00:04,233 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=YYY&alt=json
2020-04-04 12:00:04,350 INFO transport.py:185] Refreshing due to a 401 (attempt 1/2)
2020-04-04 12:00:04,404 INFO client.py:777] Refreshing access_token
2020-04-04 12:00:04,681 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=YYY&alt=json
2020-04-04 12:00:04,890 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=YYY&alt=json
2020-04-04 12:00:05,101 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=YYY&alt=json
2020-04-04 12:00:05,292 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40gmail.com/events?singleEvents=true&syncToken=YYY&alt=json
2020-04-04 12:00:05,507 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40gmail.com/events?singleEvents=true&syncToken=YYY&alt=json
2020-04-04 12:00:05,703 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=YYY&alt=json
2020-04-04 12:00:05,879 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&syncToken=YYY&alt=json returned "Not Found">
2020-04-04 12:00:05,891 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json
2020-04-04 12:00:06,044 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json returned "Not Found">
2020-04-04 12:00:06,053 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json
2020-04-04 12:00:06,203 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json returned "Not Found">
2020-04-04 12:00:06,215 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json

 ...

2020-04-04 18:04:56,854 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json
2020-04-04 18:04:57,012 ERROR google.py:45] Error during event fetch:
Traceback (most recent call last):
  File "lib/python3.6/site-packages/metabot/calendars/google.py", line 43, in poll
    pageToken=page_token).execute()
  File "lib/python3.6/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper
    return wrapped(*args, **kwargs)
  File "lib/python3.6/site-packages/googleapiclient/http.py", line 856, in execute
    raise HttpError(resp, content, uri=self.uri)
googleapiclient.errors.HttpError: <HttpError 404 when requesting https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json returned "Not Found">
2020-04-04 18:04:57,017 INFO discovery.py:867] URL being requested: GET https://www.googleapis.com/calendar/v3/calendars/XXX%40group.calendar.google.com/events?singleEvents=true&alt=json

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@nmlorg nmlorg

Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@nmlorg