[BUG] [FlyteAdmin] [scheduledWorkflowExecutor] SQS subscriber client stopped working

[rstanevich]

Describe the bug

Flyteadmin scheduledWorkflowExecutor worked successfully ~2 weeks with no redeployment.

But one day:

• SQS client had been shutted down
• Async Scheduler stopped working
• FlyteAdmin continued running with no scheduledWorkflowExecutor
• Cloudwatch events continued push messages to the queue and it was being increased.

What logs I'd got before the scheduler stopped working:

{"json":{"src":"base.go:138"},"level":"info","msg":"Successfully started running the scheduled workflow executor","ts":"2020-03-07T05:39:04Z"}

https://github.com/lyft/flyteadmin/blob/60b4c876ea105d4c79e3cad7d56fde6b9c208bcd/pkg/rpc/adminservice/base.go#L138L139
Normally, this log doesn't appear when FlyteAdmin starts. And if I understand correctly this log shouldn't appear because this row is not reachable.
Unfortunately, there is no more logs.

Expected behavior

• If is it possible to show the errors in logs from consumer connection if client shutdown
  https://github.com/nytimes/gizmo/blob/master/pubsub/pubsub.go#L44
• Retry mechanism for gizmo client or smth else

Flyte component

• [+] FlyteAdmin (Control Plane service) UPD: image: docker.io/lyft/flyteadmin:v0.2.1

To Reproduce
Steps to reproduce the behavior:

1. Scheduler config in FlyteAdmin:

scheduler:
  eventScheduler:
    scheme: aws
    region: "us-east-1"
    scheduleRole: "arn:aws:iam::{{ AWS_ACCOUNT_ID }}:role/flyte_cron_scheduler_role"
    targetName: "arn:aws:sqs:us-east-1:{{ AWS_ACCOUNT_ID }}:flyte-cron-scheduler-queue"
  workflowExecutor:
    scheme: aws
    region: "us-east-1"
    scheduleQueueName: "flyte-cron-scheduler-queue"
    accountId: "{{ AWS_ACCOUNT_ID }}"  

2. Run FlyteAdmin and wait for this message (I don't know what was the reason and how to reproduce it) :)
   {"json":{"src":"base.go:138"},"level":"info","msg":"Successfully started running the scheduled workflow executor","ts":"2020-03-07T05:39:04Z"}

Environment
Flyte component

• [+] Cloud hosted
  • [+] AWS

Others
Restarting of the FlyteAdmin pod initialized new scheduledWorkflowExecutor and the SQS events were executed.

Thank you!

[kumare3]

Hi @rstanevich thank you for the bug. This is highly unexpected and undesirable behavior. What version of FlyteAdmin are you running?

[rstanevich]

Thanks @kumare3 for your response!
We use this docker image docker.io/lyft/flyteadmin:v0.2.1

[rstanevich]

looks like I duplicated this issue #88

[kumare3]

That is right - @katrogan did you get a chance to look at the #88

[anandswaminathan]

@kumare3 I looked into this a bit, and am unable to reproduce. It is hard for me to say which part is failing, as there are several integration points. I believe the only option is add more debug logs and try to repro.

cc @katrogan if you were able to find the root cause.

[kumare3]

Yes @katrogan confirmed she is on it. I will close this one and keep the root open @rstanevich

[katrogan]

It's on the backlog but I'm not actively taking a look. @anandswaminathan i honestly don't remember anything from when i looked at this when l5 ran into it. feel free to take this over if you want

[rstanevich]

I'd like to show our case which strange enough

from the logs:

{"json":{"src":"workflow_executor.go:260"},"level":"error","msg":"Gizmo subscriber closed channel with err: [RequestError: send request failed\ncaused by: Post https://sqs.us-east-1.amazonaws.com/: read tcp 10.200.29.153:38402-\u003e52.46.130.43:443: read: connection reset by peer]","ts":"2020-12-07T22:51:52Z"}
"json":{"src":"workflow_executor.go:178"},"level":"error","msg":"error with workflow executor err: [RequestError: send request failed\ncaused by: Post https://sqs.us-east-1.amazonaws.com/: read tcp 10.200.29.153:38402-\u003e52.46.130.43:443: read: connection reset by peer] ","ts":"2020-12-07T22:51:52Z"}
{"json":{"src":"workflow_executor.go:176"},"level":"warning","msg":"Starting workflow executor","ts":"2020-12-07T22:52:22Z"}

we see that at 22:51 the connection to SQS has been reset and at 22:52 the next subscriber loop has been started (according to https://github.com/lyft/flyteadmin/blob/v0.3.7/pkg/async/schedule/aws/workflow_executor.go#L174-L183)

But in 30mins new message appeared in SQS and it hasn't been handled by this subscriber. The messages from the queue started processing after restarting flyteadmin pod. See the screenshot

Do you have an idea what could happened with this client. I am also trying figuring out what the reason. I am not familiar with gizmo client, maybe the client there is some stop method or smth else?
WDYT? cc @katrogan thank you in advance!