{"action":"created","issue":{"url":"https://api.github.com/repos/mozilla/fxa/issues/305","repository_url":"https://api.github.com/repos/mozilla/fxa","labels_url":"https://api.github.com/repos/mozilla/fxa/issues/305/labels{/name}","comments_url":"https://api.github.com/repos/mozilla/fxa/issues/305/comments","events_url":"https://api.github.com/repos/mozilla/fxa/issues/305/events","html_url":"https://github.com/mozilla/fxa/issues/305","id":343194120,"node_id":"MDU6SXNzdWUzNDMxOTQxMjA=","number":305,"title":"FxA Returning invalid verification code","user":{"login":"jrbenny35","id":5751892,"node_id":"MDQ6VXNlcjU3NTE4OTI=","avatar_url":"https://avatars2.githubusercontent.com/u/5751892?v=4","gravatar_id":"","url":"https://api.github.com/users/jrbenny35","html_url":"https://github.com/jrbenny35","followers_url":"https://api.github.com/users/jrbenny35/followers","following_url":"https://api.github.com/users/jrbenny35/following{/other_user}","gists_url":"https://api.github.com/users/jrbenny35/gists{/gist_id}","starred_url":"https://api.github.com/users/jrbenny35/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jrbenny35/subscriptions","organizations_url":"https://api.github.com/users/jrbenny35/orgs","repos_url":"https://api.github.com/users/jrbenny35/repos","events_url":"https://api.github.com/users/jrbenny35/events{/privacy}","received_events_url":"https://api.github.com/users/jrbenny35/received_events","type":"User","site_admin":false},"labels":[{"id":910961988,"node_id":"MDU6TGFiZWw5MTA5NjE5ODg=","url":"https://api.github.com/repos/mozilla/fxa/labels/P2","name":"P2","color":"dddd33","default":false},{"id":241440808,"node_id":"MDU6TGFiZWwyNDE0NDA4MDg=","url":"https://api.github.com/repos/mozilla/fxa/labels/waffle:backlog","name":"waffle:backlog","color":"ededed","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":5,"created_at":"2018-07-20T17:50:20Z","updated_at":"2018-07-24T16:01:02Z","closed_at":null,"author_association":"NONE","body":"This just started randomly on the [addons-server circleci](https://circleci.com/gh/mozilla/addons-server/tree/master).\r\nLogs:\r\n```\r\nfxa_client = <fxa.core.Client object at 0x7fd87b317d50>\r\nfxa_email = 'uitest@restmail.net'\r\n\r\n@pytest.fixture\r\ndef fxa_account(fxa_client, fxa_email):\r\nlogger = logging.getLogger()\r\naccount = TestEmailAccount(email=fxa_email)\r\npassword = ''.join([random.choice(string.ascii_letters) for i in range(8)])\r\nFxAccount = collections.namedtuple('FxAccount', 'email password')\r\nfxa_account = FxAccount(email=account.email, password=password)\r\nsession = fxa_client.create_account(fxa_account.email,\r\nfxa_account.password)\r\nlogger.info('Created: {}'.format(fxa_account))\r\naccount.fetch()\r\nmessage = account.wait_for_email(lambda m: 'x-verify-code' in m['headers'])\r\n> session.verify_email_code(message['headers']['x-verify-code'])\r\n\r\nFxAccount = <class 'pytest_fxa.plugin.FxAccount'>\r\naccount = <fxa.tests.utils.TestEmailAccount object at 0x7fd87b442bd0>\r\nfxa_account = FxAccount(email='uitest@restmail.net', password='hdIPrwgP')\r\nfxa_client = <fxa.core.Client object at 0x7fd87b317d50>\r\nfxa_email = 'uitest@restmail.net'\r\ni = 7\r\nlogger = <logging.RootLogger object at 0x7fd88412ba90>\r\nmessage = {'date': '2018-07-19T05:23:53.000Z', 'from': [{'address': 'verification@stable.dev.lcip.org', 'name': 'Firefox Account...\"description\" content=\"Verify your email to finish your Firefox Account registration\"/>\r\n</div>\r\n\r\n</body>\r\n</html>\r\n', ...}\r\npassword = 'hdIPrwgP'\r\nsession = <fxa.core.Session object at 0x7fd87b5386d0>\r\n\r\n.tox/ui-tests/local/lib/python2.7/site-packages/pytest_fxa/plugin.py:60:\r\n_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _\r\n\r\nself = <fxa.core.Session object at 0x7fd87b5386d0>\r\ncode = '8897ddd8454c260de07d60b7f85430db'\r\n\r\ndef verify_email_code(self, code):\r\n> return self.client.verify_email_code(self.uid, code) # note: not authenticated\r\n\r\ncode = '8897ddd8454c260de07d60b7f85430db'\r\nself = <fxa.core.Session object at 0x7fd87b5386d0>\r\n\r\n.tox/ui-tests/local/lib/python2.7/site-packages/fxa/core.py:311:\r\n_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _\r\n\r\nself = <fxa.core.Client object at 0x7fd87b317d50>\r\nuid = '2853d79b4ea3421c8fee2b837dd0b577'\r\ncode = '8897ddd8454c260de07d60b7f85430db'\r\n\r\ndef verify_email_code(self, uid, code):\r\nbody = {\r\n\"uid\": uid,\r\n\"code\": code,\r\n}\r\nurl = \"/recovery_email/verify_code\"\r\n> return self.apiclient.post(url, body)\r\n\r\nbody = {'code': '8897ddd8454c260de07d60b7f85430db', 'uid': '2853d79b4ea3421c8fee2b837dd0b577'}\r\ncode = '8897ddd8454c260de07d60b7f85430db'\r\nself = <fxa.core.Client object at 0x7fd87b317d50>\r\nuid = '2853d79b4ea3421c8fee2b837dd0b577'\r\nurl = '/recovery_email/verify_code'\r\n\r\n.tox/ui-tests/local/lib/python2.7/site-packages/fxa/core.py:227:\r\n_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _\r\n\r\nself = <fxa._utils.APIClient object at 0x7fd87b317b90>\r\nurl = '/recovery_email/verify_code'\r\njson = {'code': '8897ddd8454c260de07d60b7f85430db', 'uid': '2853d79b4ea3421c8fee2b837dd0b577'}\r\nkwds = {}\r\n\r\ndef post(self, url, json=None, **kwds):\r\n> return self.request(\"POST\", url, json, **kwds)\r\n\r\njson = {'code': '8897ddd8454c260de07d60b7f85430db', 'uid': '2853d79b4ea3421c8fee2b837dd0b577'}\r\nkwds = {}\r\nself = <fxa._utils.APIClient object at 0x7fd87b317b90>\r\nurl = '/recovery_email/verify_code'\r\n\r\n.tox/ui-tests/local/lib/python2.7/site-packages/fxa/_utils.py:334:\r\n_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _\r\n\r\nself = <fxa._utils.APIClient object at 0x7fd87b317b90>, method = 'POST'\r\nurl = 'https://stable.dev.lcip.org/auth/v1/recovery_email/verify_code'\r\njson = {'code': '8897ddd8454c260de07d60b7f85430db', 'uid': '2853d79b4ea3421c8fee2b837dd0b577'}\r\nretry_auth_errors = True\r\nkwds = {'headers': {'User-Agent': 'Mozilla/5.0 (Mobile; Firefox Accounts; rv:1.0) PyFxA/0.6.0 python-requests/2.19.1'}, 'timeout': 30}\r\nresp = <Response [400]>\r\nheaders = {'User-Agent': 'Mozilla/5.0 (Mobile; Firefox Accounts; rv:1.0) PyFxA/0.6.0 python-requests/2.19.1'}\r\ncontent_type = 'application/json; charset=utf-8'\r\nbody = {'code': 400, 'errno': 105, 'error': 'Bad Request', 'info': 'https://github.com/mozilla/fxa-auth-server/blob/master/docs/api.md#response-format', ...}\r\n\r\ndef request(self, method, url, json=None, retry_auth_errors=True, **kwds):\r\n\"\"\"Make a request to the API and process the response.\r\n\r\nThis method implements the low-level details of interacting with an\r\nFxA Web API, stripping away most of the details of HTTP. It will\r\nreturn the parsed JSON of a successful responses, or raise an exception\r\nfor an error response. It's also responsible for backoff handling\r\nand clock-skew tracking.\r\n\"\"\"\r\n# Don't make requests if we're in backoff.\r\n# Instead just synthesize a backoff response.\r\nif self._backoff_response is not None:\r\nif self._backoff_until >= self.client_curtime():\r\nresp = pickle.loads(self._backoff_response)\r\nresp.request = None\r\nresp.headers[\"Timestamp\"] = str(int(self.server_curtime()))\r\nreturn resp\r\nelse:\r\nself._backoff_until = 0\r\nself._backoff_response = None\r\n\r\n# Apply defaults and perform the request.\r\nwhile url.startswith(\"/\"):\r\nurl = url[1:]\r\nif not self.server_url.endswith(\"/\"):\r\nself.server_url = self.server_url + \"/\"\r\nurl = urljoin(self.server_url, url)\r\nif self.timeout is not None:\r\nkwds.setdefault(\"timeout\", self.timeout)\r\n\r\n# Configure the user agent\r\nheaders = kwds.get('headers', {})\r\nheaders.setdefault('User-Agent', USER_AGENT_HEADER)\r\nkwds['headers'] = headers\r\n\r\nresp = self._session.request(method, url, json=json, **kwds)\r\n\r\n# Everything should return a valid JSON response. Even errors.\r\ncontent_type = resp.headers.get(\"content-type\", \"\")\r\nif not content_type.startswith(\"application/json\"):\r\nmsg = \"API responded with non-json content-type: {0}\"\r\nraise fxa.errors.OutOfProtocolError(msg.format(content_type))\r\ntry:\r\nbody = resp.json()\r\nexcept ValueError as e:\r\nmsg = \"API responded with invalid json: {0}\"\r\nraise fxa.errors.OutOfProtocolError(msg.format(e))\r\n\r\n# Check for backoff indicator from the server.\r\n# If found, backoff up to the client-specified max time.\r\nif resp.status_code in (429, 500, 503):\r\ntry:\r\nretry_after = int(resp.headers[\"retry-after\"])\r\nexcept (KeyError, ValueError):\r\npass\r\nelse:\r\nif self.max_retry_after is not None:\r\nretry_after = max(retry_after, self.max_retry_after)\r\nself._backoff_until = self.client_curtime() + retry_after\r\nself._backoff_response = pickle.dumps(resp)\r\n\r\n# If we get a 401 with \"serverTime\" field in the body, then we're\r\n# probably out of sync with the server's clock. Check our skew,\r\n# adjust if necessary and try again.\r\nif retry_auth_errors:\r\nif resp.status_code == 401 and \"serverTime\" in body:\r\ntry:\r\nserver_timestamp = int(body[\"serverTime\"])\r\nexcept ValueError:\r\nmsg = \"API responded with non-integer serverTime: {0}\"\r\nmsg = msg.format(body[\"serverTime\"])\r\nraise fxa.errors.OutOfProtocolError(msg)\r\n# If our guestimate is more than 30 seconds out, try again.\r\n# This assumes the auth hook will use the updated clockskew.\r\nif abs(server_timestamp - self.server_curtime()) > 30:\r\nself._clockskew = server_timestamp - self.client_curtime()\r\nreturn self.request(method, url, json, False, **kwds)\r\n\r\n# See if we need to adjust for clock skew between client and server.\r\n# We do this automatically once per session in the hopes of avoiding\r\n# having to retry subsequent auth failures. We do it *after* the retry\r\n# checking above, because it wrecks the \"were we out of sync?\" check.\r\nif self._clockskew is None and \"timestamp\" in resp.headers:\r\ntry:\r\nserver_timestamp = int(resp.headers[\"timestamp\"])\r\nexcept ValueError:\r\nmsg = \"API responded with non-integer timestamp: {0}\"\r\nmsg = msg.format(resp.headers[\"timestamp\"])\r\nraise fxa.errors.OutOfProtocolError(msg)\r\nelse:\r\nself._clockskew = server_timestamp - self.client_curtime()\r\n\r\n# Raise exceptions for any error responses.\r\n# XXX TODO: hooks for raising error subclass based on errno.\r\nif 400 <= resp.status_code < 500:\r\n> raise fxa.errors.ClientError(body)\r\nE           ClientError: Invalid verification code\r\n\r\nbody = {'code': 400, 'errno': 105, 'error': 'Bad Request', 'info': 'https://github.com/mozilla/fxa-auth-server/blob/master/docs/api.md#response-format', ...}\r\ncontent_type = 'application/json; charset=utf-8'\r\nheaders = {'User-Agent': 'Mozilla/5.0 (Mobile; Firefox Accounts; rv:1.0) PyFxA/0.6.0 python-requests/2.19.1'}\r\njson = {'code': '8897ddd8454c260de07d60b7f85430db', 'uid': '2853d79b4ea3421c8fee2b837dd0b577'}\r\nkwds = {'headers': {'User-Agent': 'Mozilla/5.0 (Mobile; Firefox Accounts; rv:1.0) PyFxA/0.6.0 python-requests/2.19.1'}, 'timeout': 30}\r\nmethod = 'POST'\r\nresp = <Response [400]>\r\nretry_auth_errors = True\r\nself = <fxa._utils.APIClient object at 0x7fd87b317b90>\r\nurl = 'https://stable.dev.lcip.org/auth/v1/recovery_email/verify_code'\r\n\r\n.tox/ui-tests/local/lib/python2.7/site-packages/fxa/_utils.py:320: ClientError\r\n------------------------------ Captured log setup ------------------------------\r\nplugin.py 57 INFO Created: FxAccount(email='uitest@restmail.net', password='hdIPrwgP')------------------------------- pytest-selenium --------------------------------\r\nDriver log: /tmp/pytest-of-circleci/pytest-0/test_devhub_addon_upload_Resol0/driver.log URL: about:blank WARNING: Failed to gather log types: Message: GET /session/ec215684-0497-45a1-b137-34eb12f0ea41/log/types did not match a known command\r\n```"},"comment":{"url":"https://api.github.com/repos/mozilla/fxa/issues/comments/407459822","html_url":"https://github.com/mozilla/fxa/issues/305#issuecomment-407459822","issue_url":"https://api.github.com/repos/mozilla/fxa/issues/305","id":407459822,"node_id":"MDEyOklzc3VlQ29tbWVudDQwNzQ1OTgyMg==","user":{"login":"shane-tomlinson","id":848085,"node_id":"MDQ6VXNlcjg0ODA4NQ==","avatar_url":"https://avatars3.githubusercontent.com/u/848085?v=4","gravatar_id":"","url":"https://api.github.com/users/shane-tomlinson","html_url":"https://github.com/shane-tomlinson","followers_url":"https://api.github.com/users/shane-tomlinson/followers","following_url":"https://api.github.com/users/shane-tomlinson/following{/other_user}","gists_url":"https://api.github.com/users/shane-tomlinson/gists{/gist_id}","starred_url":"https://api.github.com/users/shane-tomlinson/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/shane-tomlinson/subscriptions","organizations_url":"https://api.github.com/users/shane-tomlinson/orgs","repos_url":"https://api.github.com/users/shane-tomlinson/repos","events_url":"https://api.github.com/users/shane-tomlinson/events{/privacy}","received_events_url":"https://api.github.com/users/shane-tomlinson/received_events","type":"User","site_admin":false},"created_at":"2018-07-24T16:01:02Z","updated_at":"2018-07-24T16:01:02Z","author_association":"MEMBER","body":"We have resolved this issue. These the things we noticed:\r\n\r\n1. The test runner always uses the same email address, uitest@restmail.net\r\n2. If the test runner fails creating & verifying an account, the [emails for that address are not deleted](https://github.com/mozilla/pytest-fxa/blob/master/pytest_fxa/plugin.py#L86).\r\n3. PyFxA always [returns the first email that matches the predicate](https://github.com/mozilla/PyFxA/blob/97bfe7ad53650393e1b2dffa6786e0cc2072b090/fxa/tests/utils.py#L95), which in this case the predicate is whether an email has x-verify-code header.\r\n\r\nSince the verify-code from the first email was always being returned, and then the auth-server was saying \"invalid code\", the emails for uitest were never deleted. A quick fix was to manually delete all of the emails for uitest.\r\n"}}
{"actor":{"display_login":"shane-tomlinson"}}