CODEWITHSUNDEEP
pythongoogle-cloud-functionsgoogle-cloud-scheduler
kiwinol
kiwinol

Reputation: 11

Log entries in google cloud logs duplicated the number of times function executed

I am triggering a google cloud function using a Cloud Pub/Sub trigger and Google Cloud Scheduler. Logs are duplicated the number of times the function has run on a given day. I am not sure if it hits a maximum of duplication's.

I have confirmed I don't have any loops causing the issue and tried outputting unstructured logs and didn't see the same duplication.

import logging
from google.cloud import logging as cloudlogging

# Instantiates a client
log_client = cloudlogging.Client()
log_handler = log_client.get_default_handler()
cloud_logger = logging.getLogger("cloudLogger")
cloud_logger.setLevel(logging.INFO)
cloud_logger.addHandler(log_handler)

cloud_logger.error('unable to delete from qb')

I would expect one log per log output from my script each time the script runs.

Example:

2020-10-01 15:25:04.562 AEST Unleashed_Quickbase_Jobs-1yk5flpwmlrll found

What I actually get is the above log multiplied by the number of times my script has run in the day with nearly identical timestamps see below after my scheduled script has run 3 times.

Unleashed_Quickbase_Jobs-1yk5flpwmlrll found 2020-10-01 15:25:04.564 AEST

Unleashed_Quickbase_Jobs-1yk5flpwmlrll found 2020-10-01 15:25:04.566 AEST

Unleashed_Quickbase_Jobs-1yk5flpwmlrll found 2020-10-01 15:25:04.567 AEST

I hope this makes it clearer.

Upvotes: 1

Views: 209

Answers (1)

Sayyor Y
Sayyor Y

Reputation: 1314

This issue is likely caused by one or more of the following reasons:

  1. No Explicit Acknowledgment:
    Without returning an HTTP 200 OK status, Pub/Sub assumes the message was not successfully processed and retries it. Ensure your Cloud Function explicitly returns 200 OK to acknowledge the message.

  2. Acknowledgment Deadline Too Short:
    The --ack-deadline parameter of the Pub/Sub subscription should be set to a duration that exceeds the execution time of your service (in this case, the Cloud Function). So update it as follows (e.g. 600 seconds here):

gcloud pubsub subscriptions update SUBSCRIPTION_NAME --ack-deadline=600

The maximum acknowledgment deadline supported is 10 minutes (600 seconds). If your function takes longer than 10 minutes to execute:

  • Return 200 OK before the service finishes, and handle the processing asynchronously like this:
  import asyncio

  async def process_message(data):
      await asyncio.sleep(300)  # Simulate long-running task
      print(f"Processed: {data}")

  def pubsub_handler(event, context):
      asyncio.create_task(process_message(event["data"]))
      return "Message acknowledged", 200
  • Alternatively, use Cloud Tasks to manage long-running tasks.

Upvotes: 0

Related Questions