aws-toolkit-jetbrains icon indicating copy to clipboard operation
aws-toolkit-jetbrains copied to clipboard

Unable to debug AWS Lambda function locally with Rider

Open rohit3d2003 opened this issue 5 years ago • 33 comments

I am using JetBrains Rider to debug a .Net Core AWS Lambda function locally. In 'run' configuration, I could see it executing the function and responding properly but if I try to debug ('debug' configuration) it, IDE shows an error: Function did not return value within PT30S

  • OS: macOS Big Sur
  • JetBrains product: Rider
  • JetBrains product version: 2020.2.4
  • AWS Toolkit version: 1.20-202
  • SAM CLI version: 1.10.0
  • JVM/Python version: .Net Core 3.1

rohit3d2003 avatar Nov 17 '20 01:11 rohit3d2003

When you say it ran perfectly locally, do you mean you ran it with the run config in non-debug mode?

abrooksv avatar Nov 17 '20 01:11 abrooksv

Sorry, should have been clear. Yes, it run perfectly in 'run' configuration but failed in 'debug' configuration. In the status bar, I see it waiting for the debugger and than errors out

rohit3d2003 avatar Nov 17 '20 01:11 rohit3d2003

You can check the idea.log from the Help menu to see if there is anything obvious in there. We don't have much logs to triage it sadly due to #2083 and lack of logging in the actual code.

I was not able to reproduce it locally.

abrooksv avatar Nov 17 '20 16:11 abrooksv

This is what I see in idea.log. Not sure what is missing here:

2020-11-17 08:47:05,025 | INFO | Client | FrontendToDebugWorker: start terminating lifetime 2020-11-17 08:47:05,026 | INFO | Client | FrontendToDebugWorker: termination finished 2020-11-17 08:47:05,026 | INFO | ExecutionUtil | Error running 'LoginUser':
Function did not return value within PT30S java.lang.IllegalStateException: Function did not return value within PT30S at software.aws.toolkits.jetbrains.utils.SpinUtilsKt.spinUntilResult(SpinUtils.kt:36) at software.aws.toolkits.jetbrains.utils.SpinUtilsKt$spinUntilResult$1.invokeSuspend(SpinUtils.kt) at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56) at com.intellij.openapi.application.constraints.BaseConstrainedExecution$Companion$scheduleWithinConstraints$1.invoke(BaseConstrainedExecution.kt:68) at com.intellij.openapi.application.constraints.BaseConstrainedExecution$Companion.scheduleWithinConstraints(BaseConstrainedExecution.kt:71) at com.intellij.openapi.application.constraints.BaseConstrainedExecution.scheduleWithinConstraints(BaseConstrainedExecution.kt:38) at com.intellij.openapi.application.impl.BaseExpirableExecutorMixinImpl.access$scheduleWithinConstraints$s1153900543(BaseExpirableExecutorMixinImpl.kt:12) at com.intellij.openapi.application.impl.BaseExpirableExecutorMixinImpl$scheduleWithinConstraints$$inlined$Runnable$1.run(Runnable.kt:19) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:668) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:665) at java.base/java.security.AccessController.doPrivileged(Native Method) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1.run(Executors.java:665) at java.base/java.lang.Thread.run(Thread.java:834) 2020-11-17 08:47:05,026 | ERROR | RdDispatcher | Must be executed on UI thread java.lang.IllegalStateException: |E| Wrong thread null at com.jetbrains.rdclient.protocol.RdDispatcher.assertThread(RdDispatcher.kt:58) at com.jetbrains.rd.platform.protocol.SwitchingScheduler.assertThread(SwitchingScheduler.kt:17) at com.jetbrains.rd.util.reactive.IScheduler$DefaultImpls.assertThread$default(Scheduler.kt:16) at com.jetbrains.rd.framework.base.RdReactiveBase.assertThreading(RdReactiveBase.kt:27) at com.jetbrains.rd.framework.impl.RdSignal.fire(RdSignal.kt:55) at com.jetbrains.dotCover.continuousTestingTriggers.RiderDotCoverExecutionListener.onProcessStartCompleted(RiderDotCoverExecutionListener.kt:27) at com.jetbrains.dotCover.continuousTestingTriggers.RiderDotCoverExecutionListener.processNotStarted(RiderDotCoverExecutionListener.kt:17) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at com.intellij.util.messages.impl.MessageBusImpl.invokeListener(MessageBusImpl.java:632) at com.intellij.util.messages.impl.MessageBusImpl.deliverMessage(MessageBusImpl.java:406) at com.intellij.util.messages.impl.MessageBusImpl.pumpWaitingBuses(MessageBusImpl.java:384) at com.intellij.util.messages.impl.MessageBusImpl.pumpMessages(MessageBusImpl.java:366) at com.intellij.util.messages.impl.MessageBusImpl.access$100(MessageBusImpl.java:32) at com.intellij.util.messages.impl.MessageBusImpl$MessagePublisher.invoke(MessageBusImpl.java:187) at com.sun.proxy.$Proxy151.processNotStarted(Unknown Source) at com.intellij.execution.impl.ExecutionManagerImpl.processNotStarted(ExecutionManagerImpl.kt:137) at com.intellij.execution.impl.ExecutionManagerImpl.access$processNotStarted(ExecutionManagerImpl.kt:60) at com.intellij.execution.impl.ExecutionManagerImpl$doStartRunProfile$startRunnable$1$1.invoke(ExecutionManagerImpl.kt:204) at com.intellij.execution.impl.ExecutionManagerImpl$doStartRunProfile$startRunnable$1$3.invoke(ExecutionManagerImpl.kt:253) at com.intellij.execution.impl.ExecutionManagerImpl$doStartRunProfile$startRunnable$1$3.invoke(ExecutionManagerImpl.kt:60) at com.intellij.execution.impl.ExecutionManagerImplKt$sam$java_util_function_Consumer$0.accept(ExecutionManagerImpl.kt) at org.jetbrains.concurrency.AsyncPromise$onError$1.accept(AsyncPromise.kt:94) at org.jetbrains.concurrency.AsyncPromise$onError$1.accept(AsyncPromise.kt:16) at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837) at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) at org.jetbrains.concurrency.AsyncPromise.setError(AsyncPromise.kt:153) at software.aws.toolkits.jetbrains.services.lambda.execution.local.SamInvokeRunner$execute$1$$special$$inlined$runInEdt$1$lambda$2.accept(SamInvokeRunner.kt:112) at software.aws.toolkits.jetbrains.services.lambda.execution.local.SamInvokeRunner$execute$1$$special$$inlined$runInEdt$1$lambda$2.accept(SamInvokeRunner.kt:40) at org.jetbrains.concurrency.AsyncPromise$onError$1.accept(AsyncPromise.kt:94) at org.jetbrains.concurrency.AsyncPromise$onError$1.accept(AsyncPromise.kt:16) at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837) at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) at org.jetbrains.concurrency.AsyncPromise.setError(AsyncPromise.kt:153) at software.aws.toolkits.jetbrains.services.lambda.execution.local.SamDebugger$run$3.accept(SamDebugger.kt:66) at software.aws.toolkits.jetbrains.services.lambda.execution.local.SamDebugger$run$3.accept(SamDebugger.kt:22) at org.jetbrains.concurrency.AsyncPromise$onError$1.accept(AsyncPromise.kt:94) at org.jetbrains.concurrency.AsyncPromise$onError$1.accept(AsyncPromise.kt:16) at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837) at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) at org.jetbrains.concurrency.AsyncPromise.setError(AsyncPromise.kt:153) at software.aws.toolkits.jetbrains.services.lambda.dotnet.DotNetSamDebugSupport$createDebugProcessAsync$1.invokeSuspend(DotNetSamDebugSupport.kt:218) at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56) at com.intellij.openapi.application.constraints.BaseConstrainedExecution$Companion$scheduleWithinConstraints$1.invoke(BaseConstrainedExecution.kt:68) at com.intellij.openapi.application.constraints.BaseConstrainedExecution$Companion.scheduleWithinConstraints(BaseConstrainedExecution.kt:71) at com.intellij.openapi.application.constraints.BaseConstrainedExecution.scheduleWithinConstraints(BaseConstrainedExecution.kt:38) at com.intellij.openapi.application.impl.BaseExpirableExecutorMixinImpl.access$scheduleWithinConstraints$s1153900543(BaseExpirableExecutorMixinImpl.kt:12) at com.intellij.openapi.application.impl.BaseExpirableExecutorMixinImpl$scheduleWithinConstraints$$inlined$Runnable$1.run(Runnable.kt:19) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:668) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:665) at java.base/java.security.AccessController.doPrivileged(Native Method) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1.run(Executors.java:665) at java.base/java.lang.Thread.run(Thread.java:834)

rohit3d2003 avatar Nov 17 '20 17:11 rohit3d2003

That means it is either failing to find the docker container, or the pid inside of the docker container by running the commands:

docker ps -q -f publish=[random port] or

docker exec -i [docker container from earlier command] /bin/sh -c 'for i in `ls /proc/*/exe` ; do
                    symlink=`readlink  ${'$'}i 2>/dev/null`;
                    if [[ "${'$'}symlink" == *"/dotnet" ]]; then
                        echo  ${'$'}i | sed -n 's/.*\/proc\/\(.*\)\/exe.*/\1/p'
                    fi;
                done;'

Sadly I can't tell which it is.

abrooksv avatar Nov 17 '20 17:11 abrooksv

I did install docker Hub on Mac. Do I need to have an existing docker machine running? I assumed AWS toolkit will do it automatically as long as docker software is installed.

rohit3d2003 avatar Nov 17 '20 17:11 rohit3d2003

Yes, we start the docker container. The fact that it works in non-debug mode means that your docker setup is fine.

abrooksv avatar Nov 17 '20 17:11 abrooksv

I am sad to say I will probably need to add more logging to this workflow and have you try again with the next release.

abrooksv avatar Nov 17 '20 18:11 abrooksv

Appreciate your feedback and I will switch to Visual Studio for the time being.

rohit3d2003 avatar Nov 17 '20 18:11 rohit3d2003

@abrooksv - Any update on this thread? I have the latest version installed and now it is giving little more information:

Error running 'CreateSupportAdmin': Command did not return expected result within PT30S, last attempt; cmd: 'docker ps -q -f publish=50535', exitCode: 0, stdOut: '', stdErr: ''

rohit3d2003 avatar Feb 01 '21 01:02 rohit3d2003

We have not made any progress in determining why the command can't find the docker container yet.

abrooksv avatar Feb 01 '21 01:02 abrooksv

When is the next release planned? Is there any workaround to this at the moment? I hate to use Visual Studio on Windows

rohit3d2003 avatar Feb 01 '21 15:02 rohit3d2003

I have put out a PR (https://github.com/aws/aws-toolkit-jetbrains/pull/2400) to share the hidden debug connect timeout setting with the pre-connect steps. (But the entire connect process is still governed by this timeout). It defaults to 60s so it will be longer out of the box.

I do not know exactly when the next release is, but I do know it is soon.

abrooksv avatar Feb 01 '21 16:02 abrooksv

@abrooksv - Got a new AWS ToolKit update (1.23-203) today and now when I try to debug, it errors out with 'Timeout waiting for Debugger Worker process to start'

rohit3d2003 avatar Feb 09 '21 17:02 rohit3d2003

If you open the Registry (search Registry in Cmd+Shift+A), you can try to increase the timeout. Search for "aws.debuggerAttach.timeout"

abrooksv avatar Feb 09 '21 20:02 abrooksv

Couldn't figure out where the timeout setting is mentioned? When I do Cmd+Shift+A, it opens a search within Rider. If I manually go to preferences, where should I add this setting? I am using Rider on Mac

Screen Shot 2021-02-09 at 1 22 11 PM

rohit3d2003 avatar Feb 09 '21 21:02 rohit3d2003

The setting is not visible in Preferences:

I am not too familiar with the key bindings of Rider,

Shift+Shift should work Screen Shot 2021-02-09 at 4 34 57 PM

Screen Shot 2021-02-09 at 4 38 58 PM

abrooksv avatar Feb 10 '21 00:02 abrooksv

I increased the timeout to 100000 but ran into same error.

7:25 a.m. Debugger attach error: Unable to attach to debugger process.

7:25 a.m. Error running 'CreateValuations': Timeout waiting for Debugger Worker process to start

rohit3d2003 avatar Feb 10 '21 15:02 rohit3d2003

To narrow it down even further, debugging works on Windows version of Rider. The issue only exist in macOS

rohit3d2003 avatar Feb 10 '21 23:02 rohit3d2003

I am experiencing this same issue running Rider on Big Sur. I have found that this is only happening if the Lambda runtime is set to dotnetcore3.1. In this case, while the Docker container starts up fine for running locally, debugging locally never starts the container. However, if the runtime is switched to dotnetcore2.1 the container starts.

Hope this helps.

Edit: I might also mention that I am running a case sensitive file system. This has turned out to be an issue with many other applications.

kevinlethe avatar Feb 21 '21 18:02 kevinlethe

This is the log from the dotnet3.1 RUN process that works:

2021-02-21 12:58:19,943 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 12:58:19,978 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 12:58:21,084 | DEBUG | RiderFileBreadcrumbsCollector | backend breadcrumbs support handles file = true 2021-02-21 12:58:21,085 | DEBUG | RiderFileBreadcrumbsCollector | start computing crumbs for the file file:///Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs and offset 569 2021-02-21 12:58:21,089 | DEBUG | RiderFileBreadcrumbsCollector | Have gotten crumbs from the backend: [CrumbModel: RiderClient.SolutionModel.solutions.[2].documentsOperationModel.documents.[RdProjectFileDocumentId (projectModelElementId = 906filePath = "/Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs"protocol = "file")].crumbsSession.$.crumbs.$[0], CrumbModel: RiderClient.SolutionModel.solutions.[2].documentsOperationModel.documents.[RdProjectFileDocumentId (projectModelElementId = 906filePath = "/Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs"protocol = "file")].crumbsSession.$.crumbs.$[1]] 2021-02-21 12:58:23,573 | DEBUG | RiderFileBreadcrumbsCollector | backend breadcrumbs support handles file = true 2021-02-21 12:58:23,573 | DEBUG | RiderFileBreadcrumbsCollector | start computing crumbs for the file file:///Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs and offset 569 2021-02-21 12:58:23,576 | DEBUG | RiderFileBreadcrumbsCollector | Have gotten crumbs from the backend: [CrumbModel: RiderClient.SolutionModel.solutions.[2].documentsOperationModel.documents.[RdProjectFileDocumentId (projectModelElementId = 906filePath = "/Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs"protocol = "file")].crumbsSession.$.crumbs.$[0], CrumbModel: RiderClient.SolutionModel.solutions.[2].documentsOperationModel.documents.[RdProjectFileDocumentId (projectModelElementId = 906filePath = "/Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs"protocol = "file")].crumbsSession.$.crumbs.$[1]] 2021-02-21 12:58:29,027 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 12:58:30,538 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 12:58:32,803 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 12:58:32,806 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 12:59:01,705 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 12:59:02,820 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 12:59:02,866 | DEBUG | RiderFileBreadcrumbsCollector | backend breadcrumbs support handles file = true 2021-02-21 12:59:02,866 | DEBUG | RiderFileBreadcrumbsCollector | start computing crumbs for the file file:///Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs and offset 569 2021-02-21 12:59:02,869 | DEBUG | RiderFileBreadcrumbsCollector | Have gotten crumbs from the backend: [CrumbModel: RiderClient.SolutionModel.solutions.[2].documentsOperationModel.documents.[RdProjectFileDocumentId (projectModelElementId = 906filePath = "/Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs"protocol = "file")].crumbsSession.$.crumbs.$[0], CrumbModel: RiderClient.SolutionModel.solutions.[2].documentsOperationModel.documents.[RdProjectFileDocumentId (projectModelElementId = 906filePath = "/Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs"protocol = "file")].crumbsSession.$.crumbs.$[1]]

This is the failing dotnetcore3.1 DEBUG log:

2021-02-21 13:00:50,981 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 13:00:51,130 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 13:00:52,115 | DEBUG | RiderFileBreadcrumbsCollector | backend breadcrumbs support handles file = true 2021-02-21 13:00:52,115 | DEBUG | RiderFileBreadcrumbsCollector | start computing crumbs for the file file:///Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs and offset 569 2021-02-21 13:00:52,117 | DEBUG | RiderFileBreadcrumbsCollector | Have gotten crumbs from the backend: [CrumbModel: RiderClient.SolutionModel.solutions.[2].documentsOperationModel.documents.[RdProjectFileDocumentId (projectModelElementId = 906filePath = "/Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs"protocol = "file")].crumbsSession.$.crumbs.$[0], CrumbModel: RiderClient.SolutionModel.solutions.[2].documentsOperationModel.documents.[RdProjectFileDocumentId (projectModelElementId = 906filePath = "/Users/kevin/Projects/mvplambda/MvpLambda/DrmLambda.cs"protocol = "file")].crumbsSession.$.crumbs.$[1]] 2021-02-21 13:00:59,850 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 13:01:54,227 | INFO | ServerPollingManager | Timer fired 2021-02-21 13:01:54,229 | INFO | ServerEventManager | triggering ALL events 2021-02-21 13:01:54,229 | INFO | ServerEventManager | triggering event: BUILDS_CHANGED 2021-02-21 13:01:54,229 | INFO | ServerEventManager | triggering event: PULL_REQUESTS_CHANGED 2021-02-21 13:01:54,229 | INFO | ServerEventManager | triggering event: WORK_ITEMS_CHANGED 2021-02-21 13:01:59,840 | ERROR | SamDebugger | Unable to attach to debugger process. 2021-02-21 13:01:59,857 | INFO | Client | FrontendToDebugWorker: start terminating lifetime 2021-02-21 13:01:59,858 | INFO | Client | FrontendToDebugWorker: termination finished 2021-02-21 13:01:59,858 | INFO | ExecutionUtil | Error running '[Local] MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady':
Timeout waiting for Debugger Worker process to start org.jetbrains.concurrency.MessageError: Timeout waiting for Debugger Worker process to start 2021-02-21 13:01:59,892 | INFO | LambdaHandlerValidator | Evaluating LambdaEntry(project=Project(name=mvplambda, containerState=COMPONENT_CREATED, componentStore=/Users/kevin/Projects/mvplambda), runtime=dotnetcore3.1, handler=MvpLambda::MvpLambda.DrmLambda::DrmAuthPlayReady) 2021-02-21 13:02:00,072 | WARN | DotnetDebugUtils | Failed to start debugger java.lang.IllegalStateException: Command did not return expected result within PT1M, last attempt; cmd: 'docker ps -q -f publish=55834', exitCode: 0, stdOut: '', stdErr: '' at software.aws.toolkits.jetbrains.services.lambda.dotnet.DotnetDebugUtils.runProcessUntil(DotnetDebugUtils.kt:252) at software.aws.toolkits.jetbrains.services.lambda.dotnet.DotnetDebugUtils$runProcessUntil$1.invokeSuspend(DotnetDebugUtils.kt) at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56) at com.intellij.openapi.application.constraints.BaseConstrainedExecution$Companion$scheduleWithinConstraints$1.invoke(BaseConstrainedExecution.kt:68) at com.intellij.openapi.application.constraints.BaseConstrainedExecution$Companion.scheduleWithinConstraints(BaseConstrainedExecution.kt:71) at com.intellij.openapi.application.constraints.BaseConstrainedExecution.scheduleWithinConstraints(BaseConstrainedExecution.kt:38) at com.intellij.openapi.application.impl.BaseExpirableExecutorMixinImpl.access$scheduleWithinConstraints$s1153900543(BaseExpirableExecutorMixinImpl.kt:12) at com.intellij.openapi.application.impl.BaseExpirableExecutorMixinImpl$scheduleWithinConstraints$$inlined$Runnable$1.run(Runnable.kt:19) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:668) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:665) at java.base/java.security.AccessController.doPrivileged(Native Method) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1.run(Executors.java:665) at java.base/java.lang.Thread.run(Thread.java:834)

kevinlethe avatar Feb 21 '21 21:02 kevinlethe

This seem to be working after upgrading to sam cli v1.19.1 and Rider 2021.1 EAP 5.

kevinlethe avatar Mar 04 '21 05:03 kevinlethe

Rider 2020.3.3 contains the following fix:

The overall debugger experience is as smooth and fast as it was in the 2020.2 releases, including launching the debugger, hitting breakpoints/conditional breakpoints, and evaluating values (RIDER-56637 and RIDER-56503).

I can't confirm this will help since I am not able to reproduce the issue on my machine.

abrooksv avatar Mar 26 '21 18:03 abrooksv

I'm facing the same issue. Any updates on this?

OS: macOS Big Sur 11.5.2 JetBrains product: Rider JetBrains product version: 2021.2 AWS Toolkit version: 1.31-212 SAM CLI version: 1.29.0 JVM/Python version: .Net Core 3.1

mrBaas avatar Aug 25 '21 10:08 mrBaas

Sadly, no. It is very difficult to determine the issue if we can't reproduce it locally since it involves connecting to the docker container and running the commands manually / inspecting the running processes to see what is breaking down.

Do you see the issue with the generated Hello World template in the New Project screen?

abrooksv avatar Aug 25 '21 15:08 abrooksv

Yes, I've tried the Hello World template and get the same error. What can I do to help?

mrBaas avatar Aug 26 '21 06:08 mrBaas

We need to run what the IDE does manually to see what breaks down

First make sure you hit run first before debug, so that the image is built. @rli Why did we never finish off #2454?

After you hit debug in the logs of the debug console where it is outputting you should see the SAM CLI command, something like this:

/usr/local/bin/sam local invoke HelloWorldFunction --template ...../.aws-sam/build/template.yaml --event "..../event.json" --debugger-path .....riderRD-2021.1.1/lib/ReSharperHost --debug-port 60187 --debug-port 60188

Run that in a terminal, but attach --debug to the end.

  • If the container starts (should see [Info] Waiting for the debugger to attach...), then move on.
  • If not, then hopefully the debug logs give some indication of what it is wrong, it may be as simple as mounting permissions of docker not allowing us to mount in the debugger due to docker mount permissions not allowing the Rider install location

If container is running: In another terminal, run

docker ps -q -f publish=60187

If that finds nothing then run run a normal docker ps and let us know what you do see :)

abrooksv avatar Aug 26 '21 18:08 abrooksv

Hope this helps:

I ran the following command in rider terminal:

sam local invoke HelloWorldFunction --template /Users/{replaced}/Projects/HelloWorld/.aws-sam/build/template.yaml --event "/private/var/folders/kn/wdsdn_z15hv70gj68ymjy8h40000gn/T/[Local] HelloWorldFunction-event.json" --debugger-path /Applications/Rider.app/Contents/lib/ReSharperHost --debug-port 52976 --debug-port 52977 --debug

Debug log: 2021-08-27 12:38:32,228 | Telemetry endpoint configured to be https://aws-serverless-tools-telemetry.us-west-2.amazonaws.com/metrics 2021-08-27 12:38:32,228 | Using config file: samconfig.toml, config environment: default 2021-08-27 12:38:32,228 | Expand command line arguments to: 2021-08-27 12:38:32,228 | --template_file=/Users/{replaced}/Projects/HelloWorld/.aws-sam/build/template.yaml --event=/private/var/folders/kn/wdsdn_z15hv70gj68ymjy8h40000gn/T/[Local] HelloWorldFunction-event.json --debugger_path=/Applications/Rider.app/Contents/lib/ReSharperHost --debug_port=(52976, 52977) --function_logical_id=HelloWorldFunction --no_event --layer_cache_basedir=/Users/{replaced}/.aws-sam/layers-pkg --container_host=localhost --container_host_interface=127.0.0.1 2021-08-27 12:38:32,228 | local invoke command is called 2021-08-27 12:38:32,231 | No Parameters detected in the template 2021-08-27 12:38:32,249 | 2 stacks found in the template 2021-08-27 12:38:32,249 | No Parameters detected in the template 2021-08-27 12:38:32,258 | 2 resources found in the stack 2021-08-27 12:38:32,258 | No Parameters detected in the template 2021-08-27 12:38:32,267 | Found Serverless function with name='HelloWorldFunction' and CodeUri='HelloWorldFunction' 2021-08-27 12:38:32,267 | --base-dir is not presented, adjusting uri HelloWorldFunction relative to /Users/{replaced}/Projects/HelloWorld/.aws-sam/build/template.yaml 2021-08-27 12:38:32,276 | Found one Lambda function with name 'HelloWorldFunction' 2021-08-27 12:38:32,276 | Invoking HelloWorld::HelloWorld.Function::FunctionHandler (dotnetcore3.1) 2021-08-27 12:38:32,276 | Environment variables overrides data is standard format 2021-08-27 12:38:32,277 | Loading AWS credentials from session with profile 'None' 2021-08-27 12:38:34,294 | Resolving code path. Cwd=/Users/{replaced}/Projects/HelloWorld/.aws-sam/build, CodeUri=/Users/{replaced}/Projects/HelloWorld/.aws-sam/build/HelloWorldFunction 2021-08-27 12:38:34,294 | Resolved absolute path to code is /Users/{replaced}/Projects/HelloWorld/.aws-sam/build/HelloWorldFunction 2021-08-27 12:38:34,295 | Code /Users/{replaced}/Projects/HelloWorld/.aws-sam/build/HelloWorldFunction is not a zip/jar file 2021-08-27 12:38:34,331 | Skip pulling image and use local one: public.ecr.aws/sam/emulation-dotnetcore3.1:rapid-1.28.0.

2021-08-27 12:38:34,331 | Mounting /Users/{replaced}/Projects/HelloWorld/.aws-sam/build/HelloWorldFunction as /var/task:ro,delegated inside runtime container 2021-08-27 12:38:34,658 | Setting up SIGTERM interrupt handler START RequestId: 4069a98c-4cc4-49f2-a3be-ffe9c39ca79c Version: $LATEST [Info] Waiting for the debugger to attach...

Note: I've tested this with [email protected] and v1.29.0

At this point I get following error: Find DotNet process PID has failed: Command did not return expected result within PT1M, last attempt; cmd:

'docker exec -i b7c7286cf51f /bin/sh -c "
            for i in `ls /proc/*/exe` ; do
                symlink=`readlink  $i 2>/dev/null`;
                if [[ \"$symlink\" == *\"/dotnet\" ]]; then
                    echo  $i | sed -n 's/.*\/proc\/\(.*\)\/exe.*/\1/p'
                fi;
            done;
        "', exitCode: 0, stdOut: '', stdErr: ''Attach Debugger has failed: Command did not return expected result within PT1M, last attempt; cmd: 'docker exec -i b7c7286cf51f /bin/sh -c "

Executed /bin/sh into container and tried following command:

ls /proc/*/exe 

Result: /proc/17/exe /proc/1/exe /proc/20/exe /proc/5396/exe /proc/self/exe /proc/thread-self/exe

Also tried following command inside container (while rider is waiting for debugger to attach):

for i in `ls /proc/*/exe` ; do
    symlink=`readlink  $i 2>/dev/null`;
    echo $symlink
    if [[ \"$symlink\" == *\"/dotnet\" ]]; then
        echo  $i | sed -n 's/.*\/proc\/\(.*\)\/exe.*/\1/p'
    fi;
done;

Result: /usr/bin/qemu-x86_64 /usr/bin/qemu-x86_64 /usr/bin/qemu-x86_64 /usr/bin/qemu-x86_64

/usr/bin/readlink /usr/bin/qemu-x86_64

There is no sign of any dotnet process ID.

mrBaas avatar Aug 27 '21 10:08 mrBaas

Okay, so cross architecture images are coming into play. Qemu is wrapping the dotnet process. We will need to rewrite the find PID script to deal with that in a better way.

abrooksv avatar Aug 27 '21 18:08 abrooksv

@mrBaas Here is an EAP build that contains the qemu fix for 2021.2: https://plugins.jetbrains.com/plugin/11349-aws-toolkit/versions/EAP/139608

abrooksv avatar Oct 05 '21 16:10 abrooksv