Skip to content

Instantly share code, notes, and snippets.

@sheac
Last active April 12, 2018 21:45
Show Gist options
  • Save sheac/ea51a0d777e2ec29821758c206f55c62 to your computer and use it in GitHub Desktop.
Save sheac/ea51a0d777e2ec29821758c206f55c62 to your computer and use it in GitHub Desktop.
QA'ing PA-14359 and PA-14361

Jira Tickets

1. Create a large job by copying adding this template to it about 10 times.

2. Find the job's id

select id from jobs where title = 'Shea-job-3';

-- => dc839cd8-49a6-4b8c-b282-7151448d8845

3. Check the Mothership logs for handling of oversize event:

Raw/undigested commands and results

# where are we?
[root@mothership-mothership-api-01.staging.us-west-2.aws.parsablenet.org mothership_app]$ ifconfig
...
          inet addr:10.101.1.61  Bcast:10.101.1.255  Mask:255.255.255.0
...


[root@mothership-mothership-api-01.staging.us-west-2.aws.parsablenet.org mothership_app]$ pwd

/var/log/mothership_app


# find out if/when an oversize event was produced
[root@mothership-mothership-api-01.staging.us-west-2.aws.parsablenet.org mothership_app]$ cat mothership.log | grep "Oversize message detected"

{"level":"info","time":"2018-04-12T19:08:41.672872778Z","msg":"Oversize message detected. Attempting to store in DB and send locator instead.","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","package":"event","function":"encodeMessage","messageLength":3156055,"limit":1000000}
{"level":"info","time":"2018-04-12T19:08:41.888444246Z","msg":"Oversize message detected. Attempting to store in DB and send locator instead.","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","package":"event","function":"encodeMessage","messageLength":3156055,"limit":1000000}


# use that timestamp to see what transpired
[root@mothership-mothership-api-01.staging.us-west-2.aws.parsablenet.org mothership_app]$ cat mothership.log | grep 2018-04-12T19:08:40

{"level":"info","time":"2018-04-12T19:08:40.072230822Z","msg":"JobService::Start","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","rqId":"B817F872:C635_0A6500DE:01BB_5ACFAEB7_47FCA3:1478","userId":"83316a3d-4b86-49c8-b140-63dfce2062e8","sessionId":"a873f12f-a053-4ac6-8efb-c8655d62bf18","jobId":"dc839cd8-49a6-4b8c-b282-7151448d8845","Wi-Thrift-Version":"1.15.0","Wi-Platform":"admin","Wi-App-Version":"build-4710224","httpReferer":"https://amy-reference.parsable-staging.com/jobs/Job-393/templates","jobId":"dc839cd8-49a6-4b8c-b282-7151448d8845","userName":"[email protected]","userEmail":"[email protected]"}
{"level":"warn","time":"2018-04-12T19:08:40.310050362Z","msg":"Failed to get event store from context on get","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","rqId":"B817F872:C635_0A6500DE:01BB_5ACFAEB7_47FCA3:1478","userId":"83316a3d-4b86-49c8-b140-63dfce2062e8","sessionId":"a873f12f-a053-4ac6-8efb-c8655d62bf18","jobId":"dc839cd8-49a6-4b8c-b282-7151448d8845"}

[root@mothership-mothership-api-01.staging.us-west-2.aws.parsablenet.org mothership_app]$ cat mothership.log | grep 2018-04-12T19:08:41

{"level":"info","time":"2018-04-12T19:08:41.672872778Z","msg":"Oversize message detected. Attempting to store in DB and send locator instead.","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","package":"event","function":"encodeMessage","messageLength":3156055,"limit":1000000}
{"level":"info","time":"2018-04-12T19:08:41.877794511Z","msg":"Oversize message locator stored","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","package":"event","function":"encodeMessage","messageLength":3156055,"limit":1000000,"tableName":"oversize_kafka_messages","locatorRowId":"d6e9a282-1bee-4b9e-bc88-e073fbdbd831","locatorThriftType":"job_event.JobEvent"}
{"level":"info","time":"2018-04-12T19:08:41.888444246Z","msg":"Oversize message detected. Attempting to store in DB and send locator instead.","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","package":"event","function":"encodeMessage","messageLength":3156055,"limit":1000000}

[root@mothership-mothership-api-01.staging.us-west-2.aws.parsablenet.org mothership_app]$ cat mothership.log | grep 2018-04-12T19:08:42

{"level":"info","time":"2018-04-12T19:08:42.092906129Z","msg":"Oversize message locator stored","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","package":"event","function":"encodeMessage","messageLength":3156055,"limit":1000000,"tableName":"oversize_kafka_messages","locatorRowId":"d60009a1-0b87-434c-b848-b99bafb9cc25","locatorThriftType":"job_event.JobEvent"}
{"level":"info","time":"2018-04-12T19:08:42.104415807Z","msg":"StartJob complete","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","rqId":"B817F872:C635_0A6500DE:01BB_5ACFAEB7_47FCA3:1478","userId":"83316a3d-4b86-49c8-b140-63dfce2062e8","sessionId":"a873f12f-a053-4ac6-8efb-c8655d62bf18","jobId":"dc839cd8-49a6-4b8c-b282-7151448d8845"}
{"level":"info","time":"2018-04-12T19:08:42.104642289Z","msg":"Reporting analytics for","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":30981,"exe":"mothership_linux_amd64","Event":"Job | Start","UserId":"83316a3d-4b86-49c8-b140-63dfce2062e8","Properties":{"Referer":"https://amy-reference.parsable-staging.com/jobs/Job-393/templates","Wi-App-Version":"build-4710224","Wi-Platform":"admin","Wi-Thrift-Version":"1.15.0","jobId":"dc839cd8-49a6-4b8c-b282-7151448d8845","team":"amy-reference","teamId":"6dbba898-0357-412f-82d6-d5341feb5dd0","templateId":"22282261-9845-4f72-9e47-061fab3be80e","templateVersion":54,"type":"Normal"},"caller":"config/log/use_standard_issue.go:8","logApi":"mapInterface"}

Condensed results

{"level":"info","time":"2018-04-12T19:08:40.072230822Z","msg":"JobService::Start","jobId":"dc839cd8-49a6-4b8c-b282-7151448d8845","userName":"[email protected]","userEmail":"[email protected]"}

{"level":"info","time":"2018-04-12T19:08:41.672872778Z","msg":"Oversize message detected. Attempting to store in DB and send locator instead.""function":"encodeMessage","messageLength":3156055,"limit":1000000}

{"level":"info","time":"2018-04-12T19:08:41.877794511Z","msg":"Oversize message locator stored","function":"encodeMessage","messageLength":3156055,"limit":1000000,"tableName":"oversize_kafka_messages","locatorRowId":"d6e9a282-1bee-4b9e-bc88-e073fbdbd831","locatorThriftType":"job_event.JobEvent"}

{"level":"info","time":"2018-04-12T19:08:42.104415807Z","msg":"StartJob complete","jobId":"dc839cd8-49a6-4b8c-b282-7151448d8845"}

4. Check in the DB for the locator

select * from oversize_kafka_messages where id = 'd6e9a282-1bee-4b9e-bc88-e073fbdbd831';

/*
=>
id                                   |  thrift_bytes | thrift_type         | created_at  | updated_at
-------------------------------------+---------------+---------------------+-------------+-------
d6e9a282-1bee-4b9e-bc88-e073fbdbd831 |  <binary>     | job_event.JobEvent  | 1523560122  | 1523560122
*/

5. Check in the Mothership consumer logs to see if the event was processed properly

Raw/undigested commands and results

[root@mothership-mothership-api-01.staging.us-west-2.aws.parsablenet.org mothership_app]$ cat consumer.log | grep d6e9a282-1bee-4b9e-bc88-e073fbdbd831

{"level":"info","time":"2018-04-12T19:08:42.108248013Z","msg":"Detected oversize message locator when decoding Kafka message bytes.","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","package":"event","function":"DecodeMessage","encodedMsg":"\u0018$d6e9a282-1bee-4b9e-bc88-e073fbdbd831\ufffd$31c166dc-c813-4915-b795-b4446f1da9d0\u0000","locatorRowId":"d6e9a282-1bee-4b9e-bc88-e073fbdbd831"}
{"level":"info","time":"2018-04-12T19:08:42.218535345Z","msg":"Oversize message successfully retrieved from data store","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","package":"event","function":"DecodeMessage","encodedMsg":"\u0018$d6e9a282-1bee-4b9e-bc88-e073fbdbd831\ufffd$31c166dc-c813-4915-b795-b4446f1da9d0\u0000","locatorRowId":"d6e9a282-1bee-4b9e-bc88-e073fbdbd831","messageLength":3156055}



[root@mothership-mothership-api-01.staging.us-west-2.aws.parsablenet.org mothership_app]$ cat consumer.log | grep 2018-04-12T19:08:42

{"level":"info","time":"2018-04-12T19:08:42.093736346Z","msg":"Received event","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","ConsumerGroup":"job_event_consumer","topics":"job_events","consumerGroup":"job_event_consumer"}
{"level":"info","time":"2018-04-12T19:08:42.103641708Z","msg":"Job Event HAD GOOD signature","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","ConsumerGroup":"job_event_consumer","topics":"job_events","consumerGroup":"job_event_consumer","node_version":{"SessionId":"a873f12f-a053-4ac6-8efb-c8655d62bf18","ClientSessionId":"00000000-0000-0000-0000-000000000000","SeqId":18}}
{"level":"info","time":"2018-04-12T19:08:42.108224974Z","msg":"Received event","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","ConsumerGroup":"job_event_consumer","topics":"job_events","consumerGroup":"job_event_consumer"}
{"level":"info","time":"2018-04-12T19:08:42.108248013Z","msg":"Detected oversize message locator when decoding Kafka message bytes.","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","package":"event","function":"DecodeMessage","encodedMsg":"\u0018$d6e9a282-1bee-4b9e-bc88-e073fbdbd831\ufffd$31c166dc-c813-4915-b795-b4446f1da9d0\u0000","locatorRowId":"d6e9a282-1bee-4b9e-bc88-e073fbdbd831"}
{"level":"info","time":"2018-04-12T19:08:42.218535345Z","msg":"Oversize message successfully retrieved from data store","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","package":"event","function":"DecodeMessage","encodedMsg":"\u0018$d6e9a282-1bee-4b9e-bc88-e073fbdbd831\ufffd$31c166dc-c813-4915-b795-b4446f1da9d0\u0000","locatorRowId":"d6e9a282-1bee-4b9e-bc88-e073fbdbd831","messageLength":3156055}
{"level":"info","time":"2018-04-12T19:08:42.817410313Z","msg":"Job Event HAD GOOD signature","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","ConsumerGroup":"job_event_consumer","topics":"job_events","consumerGroup":"job_event_consumer","node_version":{"SessionId":"a873f12f-a053-4ac6-8efb-c8655d62bf18","ClientSessionId":"00000000-0000-0000-0000-000000000000","SeqId":19}}
{"level":"info","time":"2018-04-12T19:08:42.81908086Z","msg":"Received event","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","ConsumerGroup":"job_event_consumer","topics":"job_events","consumerGroup":"job_event_consumer"}
{"level":"info","time":"2018-04-12T19:08:42.824467495Z","msg":"Job Event HAD GOOD signature","hostname":"mothership-mothership-api-01","hostip":"10.101.1.61","pid":31049,"exe":"mothership_linux_amd64","ConsumerGroup":"job_event_consumer","topics":"job_events","consumerGroup":"job_event_consumer","node_version":{"SessionId":"a873f12f-a053-4ac6-8efb-c8655d62bf18","ClientSessionId":"00000000-0000-0000-0000-000000000000","SeqId":20}}

Condensed Results

{"level":"info","time":"2018-04-12T19:08:42.108224974Z","msg":"Received event","ConsumerGroup":"job_event_consumer","topics":"job_events","consumerGroup":"job_event_consumer"}

{"level":"info","time":"2018-04-12T19:08:42.108248013Z","msg":"Detected oversize message locator when decoding Kafka message bytes.","function":"DecodeMessage","encodedMsg":"\u0018$d6e9a282-1bee-4b9e-bc88-e073fbdbd831\ufffd$31c166dc-c813-4915-b795-b4446f1da9d0\u0000","locatorRowId":"d6e9a282-1bee-4b9e-bc88-e073fbdbd831"}

{"level":"info","time":"2018-04-12T19:08:42.218535345Z","msg":"Oversize message successfully retrieved from data store","function":"DecodeMessage","encodedMsg":"\u0018$d6e9a282-1bee-4b9e-bc88-e073fbdbd831\ufffd$31c166dc-c813-4915-b795-b4446f1da9d0\u0000","locatorRowId":"d6e9a282-1bee-4b9e-bc88-e073fbdbd831","messageLength":3156055}

{"level":"info","time":"2018-04-12T19:08:42.817410313Z","msg":"Job Event HAD GOOD signature","ConsumerGroup":"job_event_consumer","topics":"job_events","consumerGroup":"job_event_consumer","node_version":{"SessionId":"a873f12f-a053-4ac6-8efb-c8655d62bf18","ClientSessionId":"00000000-0000-0000-0000-000000000000","SeqId":19}}

6. Check the analytics DB to see that Pumpjack was able to process the analytics event

According to analytics, the job started at 2018-04-12 19:08:40.

select job_id, title, started_at, created_at, started_by_id, lookup_id from analytics_029c.jobs where job_id = 'dc839cd8-49a6-4b8c-b282-7151448d8845';

/*
=>
job_id                                |  title       |  started_at           |  created_at           |  started_by_id                         |  lookup_id
--------------------------------------+--------------+-----------------------+-----------------------+----------------------------------------+-----------
dc839cd8-49a6-4b8c-b282-7151448d8845  |  Shea-job-3  |  2018-04-12 19:08:40  |  2018-04-12 19:07:52  |  83316a3d-4b86-49c8-b140-63dfce2062e8  |  Job-393
*/

But we want to know if the large Materialize event made it through correctly. To do this, we check the job_steps and job_step_fields tables to ensure that there are entries that correspond to the time of job start.

select count(*) from analytics_029c.job_steps where job_id = 'dc839cd8-49a6-4b8c-b282-7151448d8845' and created_at = '2018-04-12 19:08:40';

-- => 460

select count(*) from analytics_029c.job_step_fields where job_id = 'dc839cd8-49a6-4b8c-b282-7151448d8845' and created_at = '2018-04-12 19:08:40';

-- => 1355
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment