1
votes

I have a Scheduler job call my Function once an hour. The function is working without a problem and returning HTTP 200 status every time. However, every 3-5 invocations, the Scheduler job returns a HTTP 500 status. What is the cause/fix for this problem?

Example: here are what the Function logs are showing:

D 2020-02-03T10:02:10.958520185Z Function execution took 130785 ms, finished with status code: 200 
D 2020-02-03T11:01:40.819608573Z Function execution took 99762 ms, finished with status code: 200 
D 2020-02-03T12:01:41.049430737Z Function execution took 100126 ms, finished with status code: 200 
D 2020-02-03T13:02:07.369401657Z Function execution took 127213 ms, finished with status code: 200 
D 2020-02-03T14:04:24.352839424Z Function execution took 263896 ms, finished with status code: 200 
D 2020-02-03T15:03:14.664760657Z Function execution took 194125 ms, finished with status code: 200 
D 2020-02-03T16:06:23.162542969Z Function execution took 382609 ms, finished with status code: 200 
D 2020-02-03T17:03:17.458640891Z Function execution took 196799 ms, finished with status code: 200 
D 2020-02-03T18:02:54.614556691Z Function execution took 170119 ms, finished with status code: 200 
D 2020-02-03T19:04:43.064083790Z Function execution took 277775 ms, finished with status code: 200 
D 2020-02-03T20:02:59.315497864Z Function execution took 178499 ms, finished with status code: 200 

And these are examples from the logs from Scheduler

2020-02-03 11:03:00.567 CST
{"jobName":"projects/my-project/locations/us-west2/jobs/my-function-trigger","targetType":"HTTP","url":"https://us-central1-my-function.cloudfunctions.net/analytics-archiver","status":"UNKNOWN","@type":"type.googleapis.com/google.cloud.scheduler.logging.AttemptFinished"}
{
 httpRequest: {
 }
 insertId: "redacted"  
 jsonPayload: {
  @type: "type.googleapis.com/google.cloud.scheduler.logging.AttemptFinished"   
  jobName: "projects/my-project/locations/us-west2/jobs/my-function-trigger"   
  status: "UNKNOWN"   
  targetType: "HTTP"   
  url: "https://us-central1-my-project.cloudfunctions.net/my-function"   
 }
 logName: "projects/my-project/logs/cloudscheduler.googleapis.com%2Fexecutions"  
 receiveTimestamp: "2020-02-03T17:03:00.567786781Z"  
 resource: {
  labels: {
   job_id: "my-function-trigger"    
   location: "us-west2"    
   project_id: "my-function"    
  }
  type: "cloud_scheduler_job"   
 }
 severity: "ERROR"  
 timestamp: "2020-02-03T17:03:00.567786781Z"  
}


2020-02-03 13:03:00.765 CST
{"jobName":"projects/my-project/locations/us-west2/jobs/my-function-trigger","targetType":"HTTP","url":"https://us-central1-my-project.cloudfunctions.net/my-function","status":"UNKNOWN","@type":"type.googleapis.com/google.cloud.scheduler.logging.AttemptFinished"}
Expand all | Collapse all{
 httpRequest: {
 }
 insertId: "redacted"  
 jsonPayload: {
  @type: "type.googleapis.com/google.cloud.scheduler.logging.AttemptFinished"   
  jobName: "projects/my-project/locations/us-west2/jobs/my-function-trigger"   
  status: "UNKNOWN"   
  targetType: "HTTP"   
  url: "https://us-central1-my-project.cloudfunctions.net/my-function"   
 }
 logName: "projects/my-project/logs/cloudscheduler.googleapis.com%2Fexecutions"  
 receiveTimestamp: "2020-02-03T19:03:00.765993324Z"  
 resource: {
  labels: {
   job_id: "my-function-trigger"    
   location: "us-west2"    
   project_id: "my-project"    
  }
  type: "cloud_scheduler_job"   
 }
 severity: "ERROR"  
 timestamp: "2020-02-03T19:03:00.765993324Z"  
}
2
Your function calls seem to take a few minutes on average to finish, do any exceed 10 minutes? It's possible you're hitting some upper limit on how long Scheduler will wait for a response.Dustin Ingram
Did you set special timeouts/params for function and/or for Cloud Scheduler?guillaume blaquiere
@guillaume blaquiere - yes, see my comments under the answer from gso_gabrielKevin Buchs

2 Answers

1
votes

Considering the time that these requests are taking, it seems that this is causing timeout on Google Scheduler, which end up causing some invocations to fail.

As per the documentation cron.yaml Reference, you can configure there the max time that your Scheduler will take before timing out. I would recommend you to take a look at it and confirm how yours is configured and try to keep your invocations within the time set on your cron.yaml file.

Let me know if the information clarified and helped you!

0
votes

I had exactly the same problem. Although you cannot see it yet in the console, Google Cloud Scheduler has some flags you can set through the gcloud scheduler jobs create http command. This is an example I am using:

gcloud scheduler jobs create http my-job \
  --schedule="0 * * * *" \
  --uri=https://europe-west1-${PROJECT_ID}.cloudfunctions.net/my-func/ \
  --http-method=POST \
  --message-body="my-body" \
  --max-retry-attempts 3 \
  --max-backoff 10s \
  --attempt-deadline 10m

Especially the attempt-deadline seems to be important when running functions that last minutes instead of a few seconds. Setting these flags mitigated some of the problems for me, but not all. For more flags I refer you to the documentation.

Furthermore, if this does not help, it is probably a server side error somewhere under the hood of Google. This is due to the UNKNOWN error status, which you can look up in this table. Myself, I got an INTERNAL error status, which is also referred to as a server side bug. Not particularly helpful of Google..