search

mweagle / Sparta

go microservices, powered by AWS Lambda
https://gosparta.io
MIT License
717 stars 48 forks source link

Support: Example not working #145

Closed alvaroloes closed 5 years ago

alvaroloes commented 5 years ago

I have tried everything to make the example work with no luck. Everything gets correctly deployed to AWS, but when I hit "Test" the Lambda function just crashes with no information about why.

The code is the one in the example and, in case it helps, here are the ClourWatch logs produced:

{
    "BuildID": "3317be7851ebab6382ffa4d4d4fee94de0b51684",
    "SpartaSHA": "7bac54c",
    "SpartaVersion": "1.9.2",
    "UTC": "2019-05-22T14:33:29Z",
    "go Version": "go1.12.5",
    "level": "info",
    "msg": "Service: SpartaStudyStack",
    "time": "2019-05-22T14:33:29Z"
}
2019/05/22 14:33:29 <nil>
START RequestId: bc5f3a38-376d-422d-bca8-1cc5757d93ba Version: $LATEST
{
    "BuildID": "3317be7851ebab6382ffa4d4d4fee94de0b51684",
    "SpartaSHA": "7bac54c",
    "SpartaVersion": "1.9.2",
    "UTC": "2019-05-22T14:33:30Z",
    "go Version": "go1.12.5",
    "level": "info",
    "msg": "Service: SpartaStudyStack",
    "time": "2019-05-22T14:33:30Z"
}
2019/05/22 14:33:30 <nil>
END RequestId: bc5f3a38-376d-422d-bca8-1cc5757d93ba
REPORT RequestId: bc5f3a38-376d-422d-bca8-1cc5757d93ba  Duration: 486.97 ms Billed Duration: 500 ms Memory Size: 512 MB Max Memory Used: 33 MB  
RequestId: bc5f3a38-376d-422d-bca8-1cc5757d93ba Process exited before completing request

{
    "BuildID": "3317be7851ebab6382ffa4d4d4fee94de0b51684",
    "SpartaSHA": "7bac54c",
    "SpartaVersion": "1.9.2",
    "UTC": "2019-05-22T14:33:31Z",
    "go Version": "go1.12.5",
    "level": "info",
    "msg": "Service: SpartaStudyStack",
    "time": "2019-05-22T14:33:31Z"
}
2019/05/22 14:33:31 <nil>

I have checked everything (timeouts, memory, changed the signature of the Go function for the lambda, etc) but I always get the same result.

Could you please let me know what's wrong? Thanks!

mweagle commented 5 years ago

Hi @alvaroloes - couple of questions/debugging tips:

Thanks and apologies for the inconvenience. We'll get it sorted out :)

alvaroloes commented 5 years ago

Hi Matt!

Thanks for the response. These are the answers so far:

Would you post your source as a gist?

It is really just the example. Here the main.go file:

package main

import (
    "context"
    sparta "github.com/mweagle/Sparta"
)

// Standard AWS λ function
func helloWorld(ctx context.Context) (string, error) {
    return "Hello World!", nil
}

func main() {
    var lambdaFunctions []*sparta.LambdaAWSInfo
    helloWorldFn, _ := sparta.NewAWSLambda("Hello World",
        helloWorld,
        sparta.IAMRoleDefinition{})
    lambdaFunctions = append(lambdaFunctions, helloWorldFn)
    sparta.Main("SpartaStudyStack",
        "Simple Sparta application that demonstrates core functionality",
        lambdaFunctions,
        nil,
        nil)
}

And here is the go.mod file:

module serverless-panda

go 1.12

replace github.com/AlecAivazis/survey => gopkg.in/AlecAivazis/survey.v1 v1.8.4

replace gopkg.in/AlecAivazis/survey.v1 => github.com/AlecAivazis/survey v1.8.4

require (
    github.com/AlecAivazis/survey v1.8.4 // indirect
    github.com/aws/aws-lambda-go v1.10.0 // indirect
    github.com/aws/aws-sdk-go v1.19.35 // indirect
    github.com/briandowns/spinner v0.0.0-20190319032542-ac46072a5a91 // indirect
    github.com/deckarep/golang-set v1.7.1 // indirect
    github.com/dsnet/compress v0.0.1 // indirect
    github.com/dustin/go-broadcast v0.0.0-20171205050544-f664265f5a66 // indirect
    github.com/dustin/go-humanize v1.0.0 // indirect
    github.com/fatih/color v1.7.0 // indirect
    github.com/go-playground/locales v0.12.1 // indirect
    github.com/go-playground/universal-translator v0.16.0 // indirect
    github.com/golang/snappy v0.0.1 // indirect
    github.com/google/pprof v0.0.0-20190515194954-54271f7e092f // indirect
    github.com/hokaccha/go-prettyjson v0.0.0-20180920040306-f579f869bbfe // indirect
    github.com/ianlancetaylor/demangle v0.0.0-20181102032728-5e5cf60278f6 // indirect
    github.com/leodido/go-urn v1.1.0 // indirect
    github.com/magefile/mage v1.8.0 // indirect
    github.com/mholt/archiver v3.1.1+incompatible // indirect
    github.com/mweagle/Sparta v1.7.3
    github.com/mweagle/go-cloudcondenser v0.0.0-20180209031108-e1ad78f4b780 // indirect
    github.com/mweagle/go-cloudformation v0.0.0-20190424023355-c4621507eecb // indirect
    github.com/nwaples/rardecode v1.0.0 // indirect
    github.com/otiai10/copy v1.0.1 // indirect
    github.com/otiai10/curr v0.0.0-20190513014714-f5a3d24e5776 // indirect
    github.com/pierrec/lz4 v2.0.5+incompatible // indirect
    github.com/pkg/browser v0.0.0-20180916011732-0a3d74bf9ce4 // indirect
    github.com/pkg/errors v0.8.1 // indirect
    github.com/rivo/tview v0.0.0-20190515161233-bd836ef13b4b // indirect
    github.com/sirupsen/logrus v1.4.2 // indirect
    github.com/spf13/cobra v0.0.4 // indirect
    github.com/xi2/xz v0.0.0-20171230120015-48954b6210f8 // indirect
    github.com/zcalusic/sysinfo v0.0.0-20190429151633-fbadb57345c2 // indirect
    golang.org/x/net v0.0.0-20190520210107-018c4d40a106 // indirect
    gopkg.in/AlecAivazis/survey.v1 v1.8.4 // indirect
    gopkg.in/go-playground/assert.v1 v1.2.1 // indirect
    gopkg.in/go-playground/validator.v9 v9.28.0 // indirect
)

There are no more files in the project.

If you provision with --level debug as a command line argument you will see debug logs for both local (STDOUT) and remote (CloudWatch) execution. Do those logs have any more information?

I will try this! Finally, I know how to get more logging. The absence of the reason for the crash was driving me nuts. I'll let you know when I get more information

What OS are you developing on?

Mac OS Mojave

Are you testing via the AWS GUI? If so, are you supplying a sample payload?

Yes, but the sample payload is the dummy "HelloWorld" one provided by AWS. Anyway, this should not affect because the function is no using it, shouldn't it?

Will try the debug level thing and let you know the details (I guess the command is go run main.go provision --level debug --s3Bucket=$MY-BUCKET)

alvaroloes commented 5 years ago

🤔 Ok the command go run main.go provision --level debug --s3Bucket=$MY-BUCKET seemed to execute the provisioning with a debug log level, but the execution of the lambda function seems to have the info log level, so I see the same logs as those I wrote in the issue.

How can I provision in such a way that I get some debug logs of the Sparta code that is executed before my actual lambda code? It seems that it is crashing before reaching the helloWorld code.

alvaroloes commented 5 years ago

More details:

This is the AWS GUI of the lambda function generated with debug level when provisioning: image

But! as you can see in the logs, it seems that the level is again info when executing the lambda: image

mweagle commented 5 years ago

Ugh - that's a bug :(

Is there en env var SPARTA_LOG_LEVEL that you can change via the GUI to debug?

alvaroloes commented 5 years ago

Yeah! As you can see in the images above, that log level is set to DEBUG, but it seems that it is not affecting the number of logs logged in CloudWatch.

There must be something trivial that I'm not seeing

mweagle commented 5 years ago

k - I clearly broke something along the way. In the short term, change https://github.com/mweagle/Sparta/blob/master/sparta_main_awsbinary.go#L57 to use debug. It's supposed to check the log level :(

alvaroloes commented 5 years ago

Ok. I'll change it and let you know. I might take some hours because I need to leave now. Thanks for the help!

alvaroloes commented 5 years ago

@mweagle I changed that and no new logs appeared and I got the same behavior. Taking again a look at the logs, there is something strange. Check this:

START RequestId: bc5f3a38-376d-422d-bca8-1cc5757d93ba Version: $LATEST
{
    "BuildID": "3317be7851ebab6382ffa4d4d4fee94de0b51684",
    "SpartaSHA": "7bac54c",
    "SpartaVersion": "1.9.2",
    "UTC": "2019-05-22T14:33:30Z",
    "go Version": "go1.12.5",
    "level": "info",
    "msg": "Service: SpartaStudyStack",
    "time": "2019-05-22T14:33:30Z"
}
2019/05/22 14:33:30 <nil>
END RequestId: bc5f3a38-376d-422d-bca8-1cc5757d93ba
REPORT RequestId: bc5f3a38-376d-422d-bca8-1cc5757d93ba  Duration: 486.97 ms Billed Duration: 500 ms Memory Size: 512 MB Max Memory Used: 33 MB  
RequestId: bc5f3a38-376d-422d-bca8-1cc5757d93ba Process exited before completing request

Between the START and the END there is this log "2019/05/22 14:33:30 <nil>". It seems that it is login nil, which doesn't make sense. I have seen that you have different Execute() functions depending on the build tag. Maybe, when provisioning, Sparta is not compiling with the build tag lambdabinary?

I have tried to follow the code but I'm still a bit lost.

mweagle commented 5 years ago

k - I can reproduce and am looking...

mweagle commented 5 years ago

And found it...

The recent Linux update is causing platformLogSysInfo to panic when calling github.com/zcalusic/sysinfo. In the short term, if you comment out the call site here things should be back on track while I work on a better solution. Please LMK. Thanks!

alvaroloes commented 5 years ago

YES!! It is working finally!

I had already lost all hope.

Thanks a lot, @mweagle! I'll keep testing the framework 😉

mweagle commented 5 years ago

Resolved with v1.9.3. Apologies for the inconvenience.