Activity keeps timing out and return payload

I have an Activity that runs a function that makes some http calls and downloads a bunch of files. When I run this function without temporal, it works fine and does the job. When I run it using an activity then it works and downloads the files but instead of returning a confirmation string (like it should) the worker logs say:
ActivityType [FUNC_NAME ] Attempt 6 Result &Payloads{Payloads:*Payload{&Payload{Metadata:map[string]byte{encoding: [106 115 111 110 47 112 108 97 105 110],},Data:[34 83 117 99 99 101 115 115 102 117 108 108 121 32 100 111 119 110 108 111 97 100 101 100 32 102 105 108 101 115 34],},},} Error

and the worker goes for another attempt

Could anyone please help me? I’m new to Temporal and Go and am having trouble debugging this.

Can you share the workflow history for this execution?
You can get history via tctl:

tctl wf show -w <wfid> -r <runid> --of myhistory.json

Hi Tihomir!

Here’s the output I got:

1 WorkflowExecutionStarted {WorkflowType:{Name:GoogleDriveWorkflow}, ParentInitiatedEventId:0, TaskQueue:{Name:GOOGLE_DRIVE_TASK_QUEUE, Kind:Normal}, WorkflowExecutionTimeout:0s, WorkflowRunTimeout:0s, WorkflowTaskTimeout:10s, Initiator:Unspecified, OriginalExecutionRunId:e61e55d6-e9c7-4ec1-a470-2d96e08f3bf7, Identity:6036@DESKTOP-9AS8DPO@, FirstExecutionRunId:e61e55d6-e9c7-4ec1-a470-2d96e08f3bf7, Attempt:1, FirstWorkflowTaskBackoff:0s, ParentInitiatedEventVersion:0}

2 WorkflowTaskScheduled {TaskQueue:{Name:GOOGLE_DRIVE_TASK_QUEUE, Kind:Normal}, StartToCloseTimeout:10s, Attempt:1}

3 WorkflowTaskStarted {ScheduledEventId:2, Identity:40168@DESKTOP-9AS8DPO@, RequestId:5efbfa31-d044-4a42-98ce-ab31eb417a95, SuggestContinueAsNew:false, HistorySizeBytes:0}

4 WorkflowTaskCompleted {ScheduledEventId:2, StartedEventId:3, Identity:40168@DESKTOP-9AS8DPO@, BinaryChecksum:ae8f204a66bcb2d2b014ab43b3e4dba0}

5 ActivityTaskScheduled {ActivityId:5, ActivityType:{Name:GoogleDriveActivity}, TaskQueue:{Name:GOOGLE_DRIVE_TASK_QUEUE, Kind:Normal}, ScheduleToCloseTimeout:0s, ScheduleToStartTimeout:0s, StartToCloseTimeout:5s, HeartbeatTimeout:0s, WorkflowTaskCompletedEventId:4, RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2, MaximumInterval:1m40s, MaximumAttempts:0, NonRetryableErrorTypes:[]}}

@tihomir
Ok so I’ve narrowed it down to this func:

func downloadFile(filepath string, url string) (error) {
	outputFile, err := os.Create(filepath)
	if err != nil {
		return err
	}
	defer outputFile.Close()

	client := http.Client{}
	req, _ := http.NewRequest("GET", url, nil)
	req.Header.Set("User-Agent", "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36/8mqHiSuL-56")
	req.Header.Set("Cookie", "OGPC=19022622-1:; __Secure-ENID=6.SE=busPizvAYA27Ve2qiCJP2ph8ERVGfSAsHapr_QmUMvRE-c6gO2rMTk6at9RjVCLSRLhssxW8gc4bGODFsZ-VR-J2T1Uh6enOKjHoIxYBLNOD9FOENbgkhLGwug4UxARbBeURK4jnX1gcizQ80ilW5ZgNeAKv7m5Jy0yu81qrVUpXXnIzHR5vq9ZL5jc5uGqLKc368mbrSVCoKAPyv6RQq0GYbM9J9a3GwVXDpITa84AG1_e2aKurXLF3XWc; SID=OAgK6vvz6ns01vPxsb98yocHMTMm2-NjRIxw6VvPO8brH-HaL8OZ_WJi_dMAfBhtLIwfbQ.; __Secure-1PSID=OAgK6vvz6ns01vPxsb98yocHMTMm2-NjRIxw6VvPO8brH-Hahco9FG6LDCxrjrTgTWlAWQ.; __Secure-3PSID=OAgK6vvz6ns01vPxsb98yocHMTMm2-NjRIxw6VvPO8brH-HaumbUnqe3A8xD_APyKgPK2Q.; HSID=ABvaXBXFqnk8i2-EV; SSID=A7WVMP7TKT6Z2Rg9m; APISID=nOcOINKxCCENN8VB/AWe6f6Aaezu_0bl9q; SAPISID=yNyME0F4IH40cs_M/A3CTvcfy_qojqmHZf; __Secure-1PAPISID=yNyME0F4IH40cs_M/A3CTvcfy_qojqmHZf; __Secure-3PAPISID=yNyME0F4IH40cs_M/A3CTvcfy_qojqmHZf; SEARCH_SAMESITE=CgQIqJYB; NID=511=J8wwyV9IuqhhgjSEnEpjUh-QpE02YI285XsyVm4WLVkadoe7lqUVKADkaAs0RlMYErm25-FK_6kmlZaD9fqyGc1PH3n7tpaGx44u7y3K2jpT91QFqSaMO7SPQ5-Wu0j17kRQxdYn9uEKSNtLxU2k_AoBbv4eNvmW_FhehCqo9z-N5MtuAgoSoj0kFEUsQ7XsC-UOIL0s89oHnUELXkH3h94n-lGVL3H1DXKfGYsOahDmPidMTIH_GOTkmlPqPVeYObsTDCR0H-cd-vitCc0iG65nhWkK1sFwcYwZIwt1_Mb4mQ; AEC=AakniGNGUAsMbK0-4A2QWjgU1A_orqrofn0EupqiUMftMpHKspri6N8vCw; 1P_JAR=2022-09-08-11; SIDCC=AEf-XMSUD3SKRlKigOd_v9v2y1Ws7QVn3aM6-sIm7Nwbq0ROtMjAhXSS35qcMVmdxCCzvgri6w; __Secure-1PSIDCC=AEf-XMQSxEJNaDEeOQkwe-qoWwTEKjBZ2pfJ5yW-q-r4FC2q8izZ3SSHdk0c0xaHnCPeSt614A; __Secure-3PSIDCC=AEf-XMRYPdbTwXV-ppQb_3CBO2a0HAGwVw9QhO3SxGh-oVkKkl-t3IBVQGVt7Ye78-g9a4QudA")
	res, err := client.Do(req)
	if err != nil {
		return err
	}
	defer res.Body.Close()

	_, err = io.Copy(outputFile, res.Body)
	if err != nil {
		return err
	}

	return nil
}

Further I broke this down into three parts: create file, get response, save response body to file.
This code (which is running directly in acitivity.go) seems to be working fine upto the 2nd step (get response). Up to this point it does not crash, but after adding the “copy file” part it logs the result in original post.

As far as I can tell, this is a temporal problem and not a Go problem because if I run this code direct using go run then it works fine.

I wrote the entire code in python SDK and it’s still crashing:

←[2m2022-09-09T14:30:35.984065Z←[0m ←[33m WARN←[0m ←[1;33mtemporal_sdk_core::worker::activities←[0m←[33m: ←[33mActivity not found on completion. This may happen if the activity has already been cancelled but completed anyway., ←[1;33mtask_token←[0m←[33m: TaskToken(CiRiMzA5NzlhNC03MmUzLTRkZDAtODRjNS00MTI1NjNkNzEwYzgSGGdvb2dsZS1kcml2ZS13b3JrZmxvdy1pZBokNzE1ZWNhOTUtZmVkYi00MmExLTg4NGEtYTI0YzlmNTQ0MGQyIAUoATIBMUIVZ29vZ2xlX2RyaXZlX2FjdGl2aXR5SgkIBBDngYAEGAE=), ←[1;33mdetails←[0m←[33m: Status { code: NotFound, message: “invalid activityID or activity already timed out or invoking workflow is completed”, details: b"\x08\x05\x12Rinvalid activityID or activity already timed out or invoking workflow is completed\x1aB\n@type.googleapis.com/temporal.api.errordetails.v1.NotFoundFailure", metadata: MetadataMap { headers: {“content-type”: “application/grpc”} }, source: None }←[0m

Here’s the output I got:

Thanks, what would be more useful is not the output you get in terminal, but the JSON content in the output file, if you can please share that.

5 ActivityTaskScheduled {ActivityId:5, ActivityType:

Check in your web UI if for this execution there are any “Pending Activities” In web ui v1 that would be under the summary view and in v2 it would be if im correct a link on top of the page when you click into a specific execution.
Alternatively use tctl:
tctl wf desc -w <workflow_id> -r <run_id>
and look at result json look for “pendingActivities” object and see their attempt count and last failure property.

func downloadFile(filepath string, url string) (error) {

Is this a function you call from workflow or your activity code?

activity code

Ok thanks, were you also able to debug your code and see what going on? Info on debugging here.

Sorry about that.
Web UI

{
  "message": "activity StartToClose timeout",
  "source": "Server",
  "stackTrace": "",
  "cause": null,
  "timeoutFailureInfo": {
    "timeoutType": "StartToClose",
    "lastHeartbeatDetails": null
  }
}

tctl command output:

"pendingActivities": [
{
"activityId": "5",
"activityType": {
	"name": "GoogleDriveActivity"
},
"state": "Scheduled",
"lastHeartbeatTime": "2022-0909T16:27:22.713961197Z",
"attempt": 11,
"scheduledTime": "2022-09-09T16:29:07.719104942Z",
"expirationTime": "0001-01-01T00:00:00Z",
"lastFailure": {
	"message": "activity StartToClose timeout",
	"source": "Server",
	"failureType": "Failure_TimeoutFailureInfo: StartToClose"
	},
"lastWorkerIdentity": "11976@DESKTOP-9AS8DPO@"}
]
}

Your activity is scheduled with 5-second StartToCloseTimeout. So it is expected to timeout if it takes longer. I guess that your file processing logic takes longer than 5 seconds. Please read the blog post about activity timeouts.

1 Like

I changed the time for StartToCloseTimeout and it’s working fine now.
Thank you very much @tihomir @maxim