Lambda async task does not run

augustomen commented 6 years ago

Context

I have a Python 2.7 Flask app, in which I've set up a call to an async task, which I'd like to run in Lambda. I've made the default implementation with @task:

# tasks.py

@task
def verify_addresses(key):
    db = get_redis()
    record = db.get_dict(key)
    # ...long task with record
    # the function does not have a return value

However, the task does not run asynchronously at all. I've tried invoking it manually, and this is the result:

(venv)$ zappa invoke --raw production 'import tasks; tasks.verify_addresses("arg1")'
Calling invoke for stage production..
10-10T03:09:20.86Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Event before-parameter-build.lambda.Invoke: calling handler <function generate_idempotent_uuid at ox7f8c724fdaao>
[DEBUG] 2017-10-10T03:09:20.87Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Making request for OperationModel(name=Invoke) (verify_ssl=True) with params: {'body': '{"args": ["arg1"], "capture_response": false, “response_id": null, "kwargs": {}, "command": "zappa.async.route_lambda_task", "task_path": "tasks.verify_addresses"}', 'url': u'https://lambda.us-west-2.amazonaws.com/2015-03-31/functions/postcard-ninja-production/invocations', 'headers': {u'X-Amz-Invocation-Type': 'Event', 'User-Agent': 'Boto3/1.4.7 Python/2.7.12 Linux/4.9.43-17.39.amzn1.x86_64 exec-env/AWS_Lambda_python2.7 Botocore/1.7.2'}, 'context': {'auth_type': None, 'client_region': 'us-west-2', 'has_streaming_input': True, 'client_config': <botocore.config.Config object at ox7f8c6bc9f0d0>}, 'query_string': {}, 'url_path': u'/2015-03-31/functions/postcard-ninja-production/invocations', 'method': u'POST'}
[DEBUG] 2017-10-10T03:09:20.87Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Event request-created.lambda.Invoke: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7f8c6bc8ff90>>
[DEBUG] 2017-10-10T03:09:20.87Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Event choose-signer.lambda.Invoke: calling handler <function set_operation_specific_signer at ox7f8c724fd9bo>
[DEBUG] 2017-10-10T03:09:20.922 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Calculating signature using v4 auth.
[DEBUG] 2017-10-10T03:09:20.92Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob CanonicalRequest:
POST
2015-03-31/functions/postcard-ninja-production/invocations
host:lambda.us-west-2.amazonaws.com
x-amz-date:20171010T030920Z
x-amz-invocation-type:Event
x-amz-security-token:FQoDYXdzELL//////////wEaDMEDBuES82+/I/qMJiLyAUes6lstmoa4+ize+prrtUkN94tDTkaIu2iDWPy5szlmouNyXerTcsooEHJmwSerDRDqQZbeYOCchOGD9q2mfoqilSduWBsuPHCZkiHlOMSOxAYsFRQO3C/lun8bcn7sZzwVAillefh+Q7M7LOdGMkSe9vbomzbeviszaXVT+6th+HSGOd3keTm9FM/etao3fZLngTBpruu6+lMs+l7Ejlch8CszV7va3z4Adj7iCmGBsHqu5cw1AeG/oCOWwaTNKOLEw6OTB4eCZEFYSriJ23XhBok5805+kstrcDXW2ULujLrRFcKMSz8M4Fhost;x-amz-date;x-amz-invocation-type;x-amz-security-token4ado5d6aa2b2a705ceec829416623f759offf2f5aec379002c7d59oc1336d992
[DEBUG] 2017-10-10T03:09:20.92Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob StringToSign:
AWS4-HMAC-SHA256
20171010T030920Z
20171010/us-west-2/lambda/aws4_request
f8941accb52d9573d87ao86d706f8of3f191ada8382bfb18ced2c2af57c4dcf5
[DEBUG] 2017-10-10T03:09:20.92Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Signature: e5f853a9c9efo86868319da293e8oee67d3ac11eo6916cd57106efo9a726odfo
[DEBUG] 2017-10-10T03:09:20.93Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Sending http request: <PreparedRequest [POST]>
[INFO] 2017-10-10T03:09:20.94Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Starting new HTTPS connection (1): lambda.us-west-2.amazonaws.com
[DEBUG] 2017-10-10T03:09:20.1612 68932Fd5-ad68-11e7-ae78-bfe5842f9bob "POST /2015-03-31/functions/postcard-ninja-production/invocations HTTP/1.1" 202 0
[DEBUG] 2017-10-10T03:09:20.161Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Response headers: {'x-amzn-requestid': '689b9512-ad68-11e7-8c89-obdc33obe8e7', 'content-length': '0', 'x-amzn-trace-id': 'root=1-59dc39eo-ba7aab78c4e3doe94942504c;sampled=0', 'x-amzn-remapped-content-length': '0', 'connection': 'keep-alive', 'date': 'Tue, 10 Oct 2017 03:09:19 GMT', 'content-type':
[DEBUG] 2017-10-10T03:09:20.161Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Response body:
<botocore.response.StreamingBody object at ox7f8c6b638d90>
[DEBUG] 2017-10-10T03:09:20.162Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob Event needs-retry.lambda.Invoke: calling handler <botocore.retryhandler.RetryHandler object at ox7f8c6bc6a150>
[DEBUG] 2017-10-10T03:09:20.162Z 68932Fd5-ad68-11e7-ae78-bfe5842f9bob No retry needed.
[END] RequestId: 68932Fd5-ad68-11e7-ae78-bfe5842f9bob
[REPORT] RequestId: 68932Fd5-ad68-11e7-ae78-bfe5842f9bob
Duration: 77.36 ms
Billed Duration: 100 ms
Memory Size: 512 MB
Max Memory Used: 61 MB

It does run synchronously, though:

(venv)$ zappa invoke --raw production 'import app, tasks; ctx = app.app.app_context(); ctx.push(); tasks.verify_addresses.sync("arg1"); ctx.pop()'
Calling invoke For stage production..
26b78 Starting new HTTPS connection (1): api-call.com
[DEBUG] 2017-10-10T03:35:04.393Z f2548307-ad6b-11e7-bcfe-dd7eo0326b78 https://api-call.com:443 "POST /v1/verify-address HTTP/1.1" 200 292
[DEBUG] 2017-10-10T03:35:04.4222 f2548307-ad6b-11e7-bcfe-dd7eo0326b78 Starting new HTTPS connection (1): api-call.com
[DEBUG] 2017-10-10T03:35:04.517Z f2548307-ad6b-11e7-bcfe-dd7eo0326b78 https://api-call.com:443 "POST /v1/verify-address HTTP/1.1" 422 None
[DEBUG] 2017-10-10T03:35:04.56oZ f2548307-ad6b-11e7-bcfe-dd7eo0326b78 Starting new HTTPS connection (1): api-call.com
... many others like this
...
[END] RequestId: f2548307-ad6b-11e7-bcfe-dd7eo0326b78
[REPORT] RequestId: f2548307-ad6b-11e7-bcfe-dd7eo0326b78
Duration: 30015.43 ms
Billed Duration: 30000 ms
Memory Size: 512 MB
Max Memory Used: 72 MB
2017-10-1oTo3:35:09.707Z f2548307-ad6b-11e7-bcfe-dd7eo0326b78 Task timed out after 30.02 seconds

(Never mind about the timeout.) The only different thing I've done is a VPC configuration so that Zappa can use Elasticache (Redis), but that works perfectly, as you can see.

Expected Behavior

I would expect the task to be ran asynchronously, but the results don't show up in Redis, nor the debug messages in zappa tail.

Actual Behavior

It seems the task is not called at all; it is simply ignored.

Possible Fix

Could it be because the response is streamed and it's not actually pulled, thus not executing the function? Is this a default implementation?

Steps to Reproduce

The only things I've done:

Create a Zappa task with the default implementation (@task decorator)
Setup VPC so that Lambda can access the internal resources
Call the decorated function: verify_addresses("arg1")

Your Environment

Zappa version used: 0.44.3
Operating System and Python version: Linux/4.9.43-17.39.amzn1.x86_64 exec-env/AWS_Lambda_python2.7
Your zappa_settings.py:

    {
        "production": {
            "app_function": "app.app",
            "aws_region": "us-west-2",
            "profile_name": "default",
            "s3_bucket": "my-bucket-name",
            "domain": "my-domain.com",
            "certificate_arn": "arn:aws:acm:my-arn",
            "vpc_config": {
                "SubnetIds": ["subnets..."],
                "SecurityGroupIds": ["sg-..."]
            },
            "environment_variables": {
                "APICALLDOMAIN_API_KEY": "secret"
            }
        }
    }

majackson commented 6 years ago

@augustomen Are you overriding the environment variables AWS_ACCESS_KEY_ID or AWS_SECRET_ACCESS_KEY anywhere? I ran into this problem a while ago where I was overriding those env vars for access to other AWS services, and then was failing to create other lambda invocations due to not having the values set to the role used to create the invocation you are executing from.

augustomen commented 6 years ago

@majackson I had this issue as well - in which case, an error was output. After removing those variables, this is what happened. No errors, but also no work being done.

Miserlou / Zappa