googlearchive / cloud-functions-go

Unofficial Native Go Runtime for Google Cloud Functions
Apache License 2.0
423 stars 44 forks source link

How to log to GCP Stackdriver? #13

Closed choonkeat closed 6 years ago

choonkeat commented 7 years ago

I tried both log.Println and fmt.Println, neither appeared in the cloud function's log

iangudger commented 7 years ago

I am aware of the problem and working on a solution. This is listed as a limitation in the README.

choonkeat commented 7 years ago

Sorry missed that

choonkeat commented 7 years ago

Manage to get the logs appear in Global resource using "cloud.google.com/go/logging"

client, err := logging.NewClient(ctx, os.Getenv("GCLOUD_PROJECT"))
if err != nil {
  http.Error(w, err.Error(), http.StatusInternalServerError)
}
defer client.Close()
logger := client.Logger(os.Getenv("FUNCTION_NAME"))
logger.Log(logging.Entry{
  Labels: map[string]string{
    "function_name": os.Getenv("FUNCTION_NAME"),
    "project_id":    os.Getenv("GCP_PROJECT"),
  },
  Payload: "hello world"})

But when I try to specify the fields (to make it show up under the corresponding Cloud Function "view logs"), the log entries disappeared


entry := logging.Entry{
    HTTPRequest: &logging.HTTPRequest{
        Request: r,
    },
    Timestamp: time.Now(),
    Severity:  logging.Debug,
    // Trace:     r.Header.Get("X-Cloud-Trace-Context"),
    Resource: &mrpb.MonitoredResource{
        Labels: map[string]string{
            "function_name": os.Getenv("FUNCTION_NAME"),
            "project_id":    os.Getenv("GCP_PROJECT"),
            "region":        "us-central1",
        },
        Type: "cloud_function",
    },
    Labels: map[string]string{
        "execution_id": r.Header.Get("Function-Execution-Id"),
    },
    LogName: "projects/my-project/logs/cloudfunctions.googleapis.com%2Fcloud-functions",
    Payload: "hello world",
}
logger.Log(entry)

Wondering if you know the details I'm missing to make this work? If possible, I'd like to make it a middleware for easy inclusion into this project

salrashid123 commented 7 years ago

cloud logging clients would use gRPC to insert those calls and that would work fine. The otherway is to see if simple stdout can be used (which i suspect is what @iangudger is investigating).

The cloud logging would work just fine and would allow you to retarget the destination where the logs get written (i.,e to gcf logs, the the 'global' logs, etc). I'm not sure how logs 'disappeared'...but if it helps here is a sample that shows how to use the logging api and create a 'hierarchy' of logs (i.,e consolidate all log events under one parent request). Pls take a look at screenshot and the git link cited in the code (it shows the very specific sequence that allows for this; i just happened to use gae for the log target..)...we'll get that documented under cloud logging docs...

https://gist.github.com/salrashid123/310c03da383f0ac6560509045d5850fe

choonkeat commented 7 years ago

Thanks @salrashid123 that gist was helpful.

There were several problems with my earlier attempts

  1. LogName must not be specified in the logging.Entry struct, it will be an error. That's why I couldn't find my payload in GCP, i.e. "disappeared"
  2. logger := client.Logger(os.Getenv("FUNCTION_NAME")) is wrong, that's why even when my log entries did appear in GCP, they were parked under Global (and on inspection, it ignored my mrpb.MonitoredResource definition)
    • and this is actually where i needed to specify the values that will eventually become LogName

The fix

logger := client.Logger(
  "cloudfunctions.googleapis.com/cloud-functions",
  logging.CommonResource(&mrpb.MonitoredResource{
    Labels: map[string]string{
      "function_name": os.Getenv("FUNCTION_NAME"),
      "project_id":    os.Getenv("GCP_PROJECT"), // GCLOUD_PROJECT has same value ¯\_(ツ)_/¯
      "region":        "us-central1", // TODO: how do I derive this?
    },
    Type: "cloud_function",
  }),
  logging.CommonLabels(map[string]string{
    "execution_id": r.Header.Get("Function-Execution-Id"),
  }),
)

So the only pending issue is

iangudger commented 7 years ago

It appears that "us-central1" is the only supported region, so hard coding that might not be a problem.

As far as I know, GCF currently uses a different logging method that what was described by @choonkeat. I have spent some time looking into it as well as another mechanism which would be better than either.

choonkeat commented 7 years ago

So I saw some graphs appear on my Google Cloud homepage (under "APIs"). So I experimented to replace the Golang cloud function with a node js version (incoming traffic remains the same)

screen shot 2017-08-23 at 1 01 11 pm

Hmm

  1. When using Golang with cloud.google.com/go/logging solution above, the logger.Log are counted as API calls in the Google Cloud homepage
  2. When replaced with out of the box nodejs app using console.log, the logging don't seem to count to anything

This means logging is free in nodejs, but cost money in golang, right?

iangudger commented 7 years ago

This is expected. As I mentioned previously, Node.js on GCF uses a different logging mechanism. To learn more about how GCF works, I suggest you extract the worker.js file that loads your function from your instance.

choonkeat commented 6 years ago

To learn more about how GCF works, I suggest you extract the worker.js file that loads your function from your instance.

Would love to do that, but could you point me to where I can find worker.js ?

You're not talking about the index.js and node_modules/execer/index.js in my function.zip, right?

choonkeat commented 6 years ago

ok found it 🙇

choonkeat commented 6 years ago

seems like only TextPayload is accepted? Would you know of how to make supervisor receive json payload instead?

iangudger commented 6 years ago

Sorry, I don't. Why do you need that?

iangudger commented 6 years ago

@choonkeat, is there any chance you could write some instructions for others on how to extract worker.js?

choonkeat commented 6 years ago

write some instructions for others on how to extract worker.js

Will this suffice? https://gist.github.com/choonkeat/9476909becf29608844cba328cc5e3a3 or do you want me to issue a PR to add a .md file in this repo?

choonkeat commented 6 years ago

how to make supervisor receive json payload instead?

Why do you need that?

GCP log viewer allows for pretty powerful JSON querying. Will be good if I can choose to log regular string or richer data types

choonkeat commented 6 years ago

Here's the code I'm using for logging https://gist.github.com/choonkeat/dbb040845214ad21eaabfc45590e84cb

To log, I pass r *http.Request and a payload interface{}

gcpsupervisor.Log(r, payload)

If the logging via supervisor server somehow fails, it will use the Logging API to send logs of the error

Unlike worker.js which tries to accumulate log entries, checks for max number of entries, check for maximum length of payload and perform timely flush, gcpsupervisor.Log simply makes 1x HTTP POST to supervisor server every time

albertog commented 6 years ago

A temporary workaround until log will be fixed will be create a nodejs function that only write logs (standard away) and invoke this nodejs function from go functions with payload.
I do not know what will be more expensive thinking in economy or performance use Log API vs function logger on nodejs-

iangudger commented 6 years ago

@choonkeat, thanks for the worker.js instructions! A PR would be great if you can.

@albertog, the advantage of this project over alternatives such as kelseyhightower/google-cloud-functions-go is that you eliminate the Node process.