roam/daily/2020-07-16.org
2021-09-01 16:57:39 -04:00

131 lines
13 KiB
Org Mode

:PROPERTIES:
:ID: d28b1f6c-0a13-4306-86e6-d959705d3867
:END:
#+title: 2020-07-16
#+SETUPFILE: ../worklog.setup
* Import evaluation issue
Got an alert in [[id:ebea379a-8fa6-4e22-9275-a9fc98c02804][Pagerduty]] about [[file:projects/import.org][Import Evaluation]] message age.
Saw some of this earlier, where it was getting =null= for its compromised
addresses database URL. The configuration is correct in consul, so maybe this
was a weird intermittent thing.
#+begin_example
{"name":"rejected.process","levelname":"ERROR","asctime":"2020-07-16T09:49:46.103741+0000","processName":"subscriber-import-evaluation-1","message":"Error creating the consumer \"subscriber_import_evaluation.consumer.Consumer\": pgsql_compromised_addresses: null is invalid - expected format: ^postgres(ql)?://.*","module":"process","correlation_id":"c20e024c-160c-45a1-9ea3-e3bb04d26413","exc_info":["Traceback (most recent call last):\n"," File \"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/consumer.py\", line 338, in validate_settings\n jsonschema.validate(settings, self.SETTINGS_SCHEMA)\n"," File \"/usr/local/lib/python3.7/site-packages/jsonschema/validators.py\", line 899, in validate\n raise error\n","jsonschema.exceptions.ValidationError: 'null' does not match '^postgres(ql)?://.*'\n\nFailed validating 'pattern' in schema['properties']['pgsql_compromised_addresses']:\n {'description': 'The RDS compromised addresses connection URI',\n 'pattern': '^postgres(ql)?://.*',\n 'type': 'string'}\n\nOn instance['pgsql_compromised_addresses']:\n 'null'\n","\nDuring handling of the above exception, another exception occurred:\n\n","Traceback (most recent call last):\n"," File \"/usr/local/lib/python3.7/site-packages/rejected/process.py\", line 455, in get_consumer\n return handle(**kwargs)\n"," File \"/usr/local/lib/python3.7/site-packages/avroconsumer.py\", line 25, in __init__\n super(Consumer, self).__init__(*args, **kwargs)\n"," File \"/usr/local/lib/python3.7/site-packages/rejected/consumer.py\", line 208, in __init__\n self.initialize()\n"," File \"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/consumer.py\", line 291, in initialize\n self.validate_settings(self.settings.dict())\n"," File \"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/consumer.py\", line 351, in validate_settings\n raise Exception(message)\n","Exception: pgsql_compromised_addresses: null is invalid - expected format: ^postgres(ql)?://.*\n"],"log":"{\"name\":\"rejected.process\",\"levelname\":\"ERROR\",\"asctime\":\"2020-07-16T09:49:46.103741+0000\",\"processName\":\"subscriber-import-evaluation-1\",\"message\":\"Error creating the consumer \\\"subscriber_import_evaluation.consumer.Consumer\\\": pgsql_compromised_addresses: null is invalid - expected format: ^postgres(ql)?://.*\",\"module\":\"process\",\"correlation_id\":\"c20e024c-160c-45a1-9ea3-e3bb04d26413\",\"exc_info\":[\"Traceback (most recent call last):\\n\",\" File \\\"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/consumer.py\\\", line 338, in validate_settings\\n jsonschema.validate(settings, self.SETTINGS_SCHEMA)\\n\",\" File \\\"/usr/local/lib/python3.7/site-packages/jsonschema/validators.py\\\", line 899, in validate\\n raise error\\n\",\"jsonschema.exceptions.ValidationError: 'null' does not match '^postgres(ql)?://.*'\\n\\nFailed validating 'pattern' in schema['properties']['pgsql_compromised_addresses']:\\n {'description': 'The RDS compromised addresses connection URI',\\n 'pattern': '^postgres(ql)?://.*',\\n 'type': 'string'}\\n\\nOn instance['pgsql_compromised_addresses']:\\n 'null'\\n\",\"\\nDuring handling of the above exception, another exception occurred:\\n\\n\",\"Traceback (most recent call last):\\n\",\" File \\\"/usr/local/lib/python3.7/site-packages/rejected/process.py\\\", line 455, in get_consumer\\n return handle(**kwargs)\\n\",\" File \\\"/usr/local/lib/python3.7/site-packages/avroconsumer.py\\\", line 25, in __init__\\n super(Consumer, self).__init__(*args, **kwargs)\\n\",\" File \\\"/usr/local/lib/python3.7/site-packages/rejected/consumer.py\\\", line 208, in __init__\\n self.initialize()\\n\",\" File \\\"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/consumer.py\\\", line 291, in initialize\\n self.validate_settings(self.settings.dict())\\n\",\" File \\\"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/consumer.py\\\", line 351, in validate_settings\\n raise Exception(message)\\n\",\"Exception: pgsql_compromised_addresses: null is invalid - expected format: ^postgres(ql)?://.*\\n\"]}\n","stream":"stdout","docker":{"container_id":"8cee26b83b012277ad0ee740e11b260e25baed5aff912264ae195b30ace5ab21"},"kubernetes":{"container_name":"subscriber-import-evaluation","namespace_name":"cp","pod_name":"subscriber-import-evaluation-6bdd96bdcd-jx4w9","pod_id":"4e098e40-bae8-11ea-9f30-6a3b5e3f247e","labels":{"app":"subscriber-import-evaluation","component":"application","pod-template-hash":"2688526878","version":"e142756"},"host":"kube01-w02.testing.aweberint.com","master_url":"https://10.50.0.1:443/api"},"timestamp":"2020-07-16T09:49:46+00:00"}
#+end_example
Here, though, we've got a message repeatedly being requeued due to a list lookup failure.
#+begin_example
{"name":"subscriber_import_evaluation.consumer","levelname":"DEBUG","asctime":"2020-07-16T12:54:18.250984+0000","processName":"subscriber-import-evaluation-1","message":"Returning {'account': '62949269-3df5-46d9-b883-74e7771504f2', 'import_uuid': 'f4cd8ddc-95c3-445d-afbe-386e93a29854', 'legacy_account_id': 1326226, 'legacy_list_id': 5202426, 'list': 'ce641169-a75d-45bc-bc48-ef8a8bda31c8', 'timestamp': '2020-07-16T09:36:37.989035+00:00', 'acquisition_method': 'Acquisition method: \"other\"\\nProvider: Did not bring from another provider\\nDescribe how you got this list of subscribers\\nIam exporting and re-importing and merging my lists.', 'automation_enabled': True, 'coi_enabled': False, 'column_mapping': {'email': 0, 'name': 1, 'note': 8, 'tags': 19}, 'existing_subscriber_action': 'Ignore', 'remote_ip': '110.144.41.250', 'tags': [], 'message_number': None}","module":"avroconsumer","correlation_id":"43b4305c-02fa-4e5a-aba1-e7db9c4bb926","exc_info":null}
{"name":"subscriber_import_evaluation.consumer","levelname":"WARNING","asctime":"2020-07-16T12:54:18.268914+0000","processName":"subscriber-import-evaluation-1","message":"get_list: GET request to http://list.service.production.consul/v1/accounts/1326226/lists/5202426 failed with message: HTTP 404: ListNotFound","module":"services","correlation_id":"43b4305c-02fa-4e5a-aba1-e7db9c4bb926","exc_info":null}
{"name":"subscriber_import_evaluation.consumer","levelname":"ERROR","asctime":"2020-07-16T12:54:18.269250+0000","processName":"subscriber-import-evaluation-1","message":"Exception processing delivery 1: HTTP 404: ListNotFound","module":"consumer","correlation_id":"43b4305c-02fa-4e5a-aba1-e7db9c4bb926","exc_info":null}
{"name":"subscriber_import_evaluation.consumer","levelname":"ERROR","asctime":"2020-07-16T12:54:18.269401+0000","processName":"subscriber-import-evaluation-1","message":"Processor handled HTTPClientError: HTTP 404: ListNotFound","module":"consumer","correlation_id":"43b4305c-02fa-4e5a-aba1-e7db9c4bb926","exc_info":["Traceback (most recent call last):\n"," File \"/usr/local/lib/python3.7/site-packages/rejected/consumer.py\", line 908, in execute\n yield result\n"," File \"/usr/local/lib/python3.7/site-packages/tornado/gen.py\", line 735, in run\n value = future.result()\n"," File \"/usr/local/lib/python3.7/site-packages/tornado/gen.py\", line 742, in run\n yielded = self.gen.throw(*exc_info) # type: ignore\n"," File \"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/consumer.py\", line 734, in process\n fields=[\"coi_bitmap\"],\n"," File \"/usr/local/lib/python3.7/site-packages/tornado/gen.py\", line 735, in run\n value = future.result()\n"," File \"/usr/local/lib/python3.7/site-packages/tornado/gen.py\", line 742, in run\n yielded = self.gen.throw(*exc_info) # type: ignore\n"," File \"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/services.py\", line 113, in get_list\n error_reason='Unable to fetch list')\n"," File \"/usr/local/lib/python3.7/site-packages/tornado/gen.py\", line 735, in run\n value = future.result()\n"," File \"/usr/local/lib/python3.7/site-packages/tornado/gen.py\", line 742, in run\n yielded = self.gen.throw(*exc_info) # type: ignore\n"," File \"/usr/local/lib/python3.7/site-packages/subscriber_import_evaluation/services.py\", line 65, in _http_fetch\n request_timeout=request_timeout, **kwargs)\n"," File \"/usr/local/lib/python3.7/site-packages/tornado/gen.py\", line 735, in run\n value = future.result()\n","tornado.httpclient.HTTPClientError: HTTP 404: ListNotFound\n"]}
{"name":"rejected.process","levelname":"WARNING","asctime":"2020-07-16T12:54:18.281276+0000","processName":"subscriber-import-evaluation-1","message":"Rejecting message 1 with requeue","module":"process","correlation_id":"7a3a8390-10de-40ef-96be-100e8fa98596","exc_info":null}
{"name":"rejected.process","levelname":"INFO","asctime":"2020-07-16T12:54:18.281544+0000","processName":"subscriber-import-evaluation-1","message":"Resetting failure window, 1594904058 seconds since last","module":"process","correlation_id":"01ab189d-9c3e-4fb1-830b-eec0049dc434","exc_info":null}
#+end_example
The lookup fails with the account in the path, but succeeds without it?
#+begin_src http :pretty :exports both
GET http://list.service.production.consul/v1/accounts/1326226/lists/5202426
#+end_src
#+RESULTS[612dcf937d3cdea3381ed3836f7cedfdd3c23a3e]:
: {
: "error": {
: "status_code": 404,
: "exception": "ListNotFound",
: "message": "List with given id not found"
: }
: }
#+begin_src http :pretty :exports both
GET http://list.service.production.consul/v1/lists/5202426
#+end_src
#+RESULTS[67a16238d6aad00f1a7abc4a59736d3ed4f5aea4]:
#+begin_example
{
"friendly_list_name": "15 minute manifestation.",
"address_id": 779131,
"coi_confirmation_text": "",
"sender_name": "Geoff Stevens",
"coi_subject_text": "Response Required: Please confirm your request for information.\n",
"coi_button_text": "Confirm my subscription",
"contact_address": "Palmer Rd\nPortland vic 3305\nAUSTRALIA",
"list_name": "awlist5202426",
"custom_fields": {},
"coi_closing": "",
"city": "Portland",
"country_id": 13,
"zipcode": "3305",
"locale": "en-US",
"state": "vic",
"list_description": "0000000",
"coi_subject_id": 6,
"company_name": "Geoff Stevenson",
"contact_emails": [
{
"reply": 1,
"confirmation": 0,
"email": "gst1965@bigpond.com",
"name": "Geoff Stevens"
}
],
"list_id": 5202426,
"country_name": "AUSTRALIA",
"account_id": 1326226,
"address1": "Palmer Rd",
"address2": null,
"company_website": "",
"coi_bitmap": 10,
"confirmation_button_text_id": 1,
"sender_email": "gst1965@bigpond.com",
"signature": null
}
#+end_example
Popped the offending message off the queue:
Properties:
#+begin_example
app_id: subscriberimportapi/3.0.11
type: import_requested.v1
timestamp: 1594892197
message_id: e4b0e88c-d90c-4d1f-bf22-863ca6a140a7
correlation_id: 43b4305c-02fa-4e5a-aba1-e7db9c4bb926
headers:
account_id: 62949269-3df5-46d9-b883-74e7771504f2
x-shovelled:
dest-exchange: events
dest-uri: amqp://rabbitmq.aweberprod.com:5672/%2f
shovel-name: rabbitmq-events
shovel-type: dynamic
shovel-vhost: /
shovelled-by: production
src-queue: rabbitmq-events
src-uri: amqp://
content_type: application/vnd.apache.avro.datum
#+end_example
Payload:
#+begin_example
SDYyOTQ5MjY5LTNkZjUtNDZkOS1iODgzLTc0ZTc3NzE1MDRmMkhmNGNkOGRkYy05NWMzLTQ0NWQtYWZiZS0zODZlOTNhMjk4NTSk8qEB9If7BEhjZTY0MTE2
OS1hNzVkLTQ1YmMtYmM0OC1lZjhhOGJkYTMxYzhAMjAyMC0wNy0xNlQwOTozNjozNy45ODkwMzUrMDA6MDDYAkFjcXVpc2l0aW9uIG1ldGhvZDogIm90aGVy
IgpQcm92aWRlcjogRGlkIG5vdCBicmluZyBmcm9tIGFub3RoZXIgcHJvdmlkZXIKRGVzY3JpYmUgaG93IHlvdSBnb3QgdGhpcyBsaXN0IG9mIHN1YnNjcmli
ZXJzCklhbSBleHBvcnRpbmcgYW5kIHJlLWltcG9ydGluZyBhbmQgbWVyZ2luZyBteSBsaXN0cy4BAAgKZW1haWwACG5hbWUCCG5vdGUQCHRhZ3MmAAAcMTEw
LjE0NC40MS4yNTAAAA==
#+end_example
There seem to be more messages failing the same way, it'd probably be faster to just make a code change to drop messages on 4XX errors.
* Login and Landing pages
#+begin_example
# Send logged in customers to /users
RewriteCond %{HTTP:Cookie} (^|;\ *)loggedIn=1 [NC]
RewriteRule ^/(landing|login).htm$ /users [L,R=302]
#+end_example
=loginAjax= only appears to be hit from the landing/login pages:
#+begin_example
root@web-controlpanel1:/home/aweber/logs# grep loginAjax httpd/access_log |cut -d ' ' -f 14|cut -d '?' -f 1|sed 's/"//g'|sort|uniq -c
9 -
2244 https://www.aweber.com/landing.htm
500 https://www.aweber.com/login.htm
#+end_example