microservices-demo icon indicating copy to clipboard operation
microservices-demo copied to clipboard

Adservice not serving ads when deployed outside of GKE

Open ksingh7 opened this issue 3 years ago • 10 comments

Describe the bug

This is a great demo, thanks Team Google. I deployed this and was visualizing the requests from all the services. Everything looks good, except the adservice which does not invoked from any frontend call.

So i am wondering if adservice is really in use.

To Reproduce

  1. Deploy the demo
  2. Verify if adservice is functional

Logs

adservice-58b9d598d9-gnkmg                    1/1     Running   0             13m
cartservice-8f86d8667-r7f57                   1/1     Running   2 (12m ago)   13m
checkoutservice-54649bffc7-jtccc              1/1     Running   0             13m
currencyservice-5bddd57fbc-vg448              1/1     Running   0             13m
redis-cart-5998f5886b-fhp95                   1/1     Running   0             13m
frontend-86c9744b6c-4s7k7                     1/1     Running   0          24m
productcatalogservice-6b7cd9d9bf-bkfhn        1/1     Running   0          24m
recommendationservice-f8d649f45-zsng9         1/1     Running   0          24m
emailservice-84b5956b89-hk5bn                 1/1     Running   0          23m
paymentservice-6f479bc499-dgvhj               1/1     Running   0          23m
shippingservice-69567dd7bd-zm56k              1/1     Running   0          23m

Screenshots

image

Environment

K8s, multicluster

Additional context

Exposure

ksingh7 avatar Feb 14 '22 19:02 ksingh7

Or maybe if can ask from the frontend what's the way to see ads powered by adservice ?

ksingh7 avatar Feb 14 '22 19:02 ksingh7

The main diagram in readme file shows that Frontend invokes adservice, can someone point me where on frontend i can see ads ?

ksingh7 avatar Feb 14 '22 19:02 ksingh7

Logs from adsservice pod

E0214 19:28:00.031248    15 throttler_api.cc:84] GRPC: src/core/lib/security/credentials/google_default/google_default_credentials.cc:351 Could not create google default credentials: {"created":"@1644866880.028060535","description":"Failed to create Google credentials","file":"src/core/lib/security/credentials/google_default/google_default_credentials.cc","file_line":285,"referenced_errors":[{"created":"@1644866880.028062935","description":"creds_path unset","file":"src/core/lib/security/credentials/google_default/google_default_credentials.cc","file_line":229},{"created":"@1644866880.028134898","description":"Failed to load file","file":"src/core/lib/iomgr/load_file.cc","file_line":72,"filename":"//.config/gcloud/application_default_credentials.json","referenced_errors":[{"created":"@1644866880.028133578","description":"No such file or directory","errno":2,"file":"src/core/lib/iomgr/load_file.cc","file_line":45,"os_error":"No such file or directory","syscall":"fopen"}]}]}
E0214 19:28:00.031539    15 throttler_api.cc:108] Failed to get Google default credentials
E0214 19:28:00.032150    23 throttler_api.cc:288] Profiler API is not initialized, stop profiling
{"instant":{"epochSecond":1644866881,"nanoOfSecond":242000000},"thread":"main","level":"INFO","loggerName":"hipstershop.AdService","message":"Jaeger initialization disabled.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":1,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-02-14T19:28:01.242Z"}
{"instant":{"epochSecond":1644866881,"nanoOfSecond":242000000},"thread":"Thread-4","level":"INFO","loggerName":"hipstershop.AdService","message":"Stats disabled.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":14,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-02-14T19:28:01.242Z"}

ksingh7 avatar Feb 14 '22 20:02 ksingh7

Hi, great question! Could you provide some context on the visualization you've provided and where it comes from?

The frontend talks to the adservice via RPC calls, with the chain starting here: https://github.com/GoogleCloudPlatform/microservices-demo/blob/6b25a1a4f577b11cf0051505491ac128b2bf651f/src/frontend/handlers.go#L114

The connection is done here: https://github.com/GoogleCloudPlatform/microservices-demo/blob/e1c04f89be61b9af59f6a277539757675b1a60df/src/frontend/rpc.go#L119

And they appear near the bottom of the screen like so: image

@NimJay may be able to add some more context!

bourgeoisor avatar Feb 15 '22 06:02 bourgeoisor

Thanks for your input, @bourgeoisor. I think you covered everything. :) Not much to add from my end.

I just deployed Online Boutique on a Kind (non-GCP) cluster. I got the similar errors in the adservice:

E0215 20:23:21.458216    16 throttler_api.cc:85] GRPC: src/core/lib/security/credentials/google_default/google_default_credentials.cc:351 Could not create google default credentials: {"created":"@1644956601.396077434","description":"Failed to create Google credentials","file":"src/core/lib/security/credentials/google_default/google_default_credentials.cc","file_line":285,"referenced_errors":[{"created":"@1644956601.396079190","description":"creds_path unset","file":"src/core/lib/security/credentials/google_default/google_default_credentials.cc","file_line":229},{"created":"@1644956601.396883568","description":"Failed to load file","file":"src/core/lib/iomgr/load_file.cc","file_line":72,"filename":"/root/.config/gcloud/application_default_credentials.json","referenced_errors":[{"created":"@1644956601.396882722","description":"No such file or directory","errno":2,"file":"src/core/lib/iomgr/load_file.cc","file_line":45,"os_error":"No such file or directory","syscall":"fopen"}]}]}
E0215 20:23:21.458537    16 throttler_api.cc:109] Failed to get Google default credentials
E0215 20:23:21.459048    24 throttler_api.cc:290] Profiler API is not initialized, stop profiling
{"instant":{"epochSecond":1644956607,"nanoOfSecond":178000000},"thread":"Thread-4","level":"INFO","loggerName":"hipstershop.AdService","message":"Stats disabled.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":14,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-02-15T20:23:27.178Z"}
{"instant":{"epochSecond":1644956607,"nanoOfSecond":178000000},"thread":"main","level":"INFO","loggerName":"hipstershop.AdService","message":"Jaeger initialization disabled.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":1,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-02-15T20:23:27.178Z"}
{"instant":{"epochSecond":1644956608,"nanoOfSecond":473000000},"thread":"Thread-4","level":"INFO","loggerName":"hipstershop.AdService","message":"Tracing disabled.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":14,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-02-15T20:23:28.473Z"}
{"instant":{"epochSecond":1644956608,"nanoOfSecond":474000000},"thread":"main","level":"INFO","loggerName":"hipstershop.AdService","message":"AdService starting.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":1,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-02-15T20:23:28.474Z"}
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
{"instant":{"epochSecond":1644956610,"nanoOfSecond":385000000},"thread":"main","level":"INFO","loggerName":"hipstershop.AdService","message":"Ad Service started, listening on 9555","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":1,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-02-15T20:23:30.385Z"}

But the ads were displaying fine in the front-end: Screen Shot 2022-02-15 at 3 39 59 PM This means that the front-end is definitely able to reach the adservice. So I doubt these errors are a problem. 🤔

Questions

  1. As Olivier mentioned, could you please provide some more context on the diagram (e.g., what is the software/tool)?
  2. Are you using a Service Mesh? If so, could it be a problem with the proxy that's attached to the adservice?
  3. ~What kind of clusters did you deploy to (e.g., Kind, minikube, EKS, etc.)?~ I just noticed that you mentioned "GKE,EKS,AKS".

NimJay avatar Feb 15 '22 20:02 NimJay

Hi @ksingh7! I'm going to assume (due to inactivity) that you no longer need help on this ticket. Please feel free to re-open if you do. :) Closing. Thanks!

NimJay avatar Mar 01 '22 13:03 NimJay

@NimJay @bourgeoisor Hey Sorry for delayed response on this

About the Ad-service i will give it a try again, last time when i tried i had this issue that i reported in here.

About how i got the microservices data transafer/communication real-time graph, Answer is , i used https://skupper.io/ dashboard. I have deployed this microservices demo (online botique) across 3 Kubernetes clusters successfully using skupper, and skupper provides this nice dashboard.

Hope this helps.

ksingh7 avatar Mar 03 '22 21:03 ksingh7

@NimJay @bourgeoisor

So i tried ad service again today but do not se any ads in the frontend as well as do not see any traffing moving to ad service

This is deployed on a local k8s environment, not on GKE, so do i need to add any environment variable for Google Credentials as i am getting errors on ads service.

E0303 21:30:59.129546    14 throttler_api.cc:84] GRPC: src/core/lib/security/credentials/google_default/google_default_credentials.cc:351 Could not create google default credentials: {"created":"@1646343059.126572020","description":"Failed to create Google credentials","file":"src/core/lib/security/credentials/google_default/google_default_credentials.cc","file_line":285,"referenced_errors":[{"created":"@1646343059.126573722","description":"creds_path unset","file":"src/core/lib/security/credentials/google_default/google_default_credentials.cc","file_line":229},{"created":"@1646343059.126634233","description":"Failed to load file","file":"src/core/lib/iomgr/load_file.cc","file_line":72,"filename":"//.config/gcloud/application_default_credentials.json","referenced_errors":[{"created":"@1646343059.126633050","description":"No such file or directory","errno":2,"file":"src/core/lib/iomgr/load_file.cc","file_line":45,"os_error":"No such file or directory","syscall":"fopen"}]}]}
E0303 21:30:59.129770    14 throttler_api.cc:108] Failed to get Google default credentials
E0303 21:30:59.130158    22 throttler_api.cc:288] Profiler API is not initialized, stop profiling
{"instant":{"epochSecond":1646343059,"nanoOfSecond":998000000},"thread":"Thread-4","level":"INFO","loggerName":"hipstershop.AdService","message":"Stats disabled.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":14,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:30:59.998Z"}
{"instant":{"epochSecond":1646343059,"nanoOfSecond":998000000},"thread":"main","level":"INFO","loggerName":"hipstershop.AdService","message":"Jaeger initialization disabled.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":1,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:30:59.998Z"}
{"instant":{"epochSecond":1646343060,"nanoOfSecond":108000000},"thread":"Thread-4","level":"INFO","loggerName":"hipstershop.AdService","message":"Tracing disabled.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":14,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:00.108Z"}
{"instant":{"epochSecond":1646343060,"nanoOfSecond":108000000},"thread":"main","level":"INFO","loggerName":"hipstershop.AdService","message":"AdService starting.","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":1,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:00.108Z"}
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
{"instant":{"epochSecond":1646343060,"nanoOfSecond":464000000},"thread":"main","level":"INFO","loggerName":"hipstershop.AdService","message":"Ad Service started, listening on 9555","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":1,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:00.464Z"}
{"instant":{"epochSecond":1646343104,"nanoOfSecond":930000000},"thread":"grpc-default-executor-1","level":"INFO","loggerName":"hipstershop.AdService","message":"received ad request (context_words=[footwear])","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":19,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:44.930Z"}
{"instant":{"epochSecond":1646343107,"nanoOfSecond":479000000},"thread":"grpc-default-executor-1","level":"INFO","loggerName":"hipstershop.AdService","message":"received ad request (context_words=[footwear])","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":19,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:47.479Z"}
{"instant":{"epochSecond":1646343110,"nanoOfSecond":426000000},"thread":"grpc-default-executor-1","level":"INFO","loggerName":"hipstershop.AdService","message":"received ad request (context_words=[accessories])","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":19,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:50.426Z"}
{"instant":{"epochSecond":1646343112,"nanoOfSecond":971000000},"thread":"grpc-default-executor-1","level":"INFO","loggerName":"hipstershop.AdService","message":"received ad request (context_words=[hair, beauty])","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":19,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:52.971Z"}
{"instant":{"epochSecond":1646343115,"nanoOfSecond":492000000},"thread":"grpc-default-executor-1","level":"INFO","loggerName":"hipstershop.AdService","message":"received ad request (context_words=[accessories])","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":19,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:55.492Z"}
{"instant":{"epochSecond":1646343117,"nanoOfSecond":990000000},"thread":"grpc-default-executor-1","level":"INFO","loggerName":"hipstershop.AdService","message":"received ad request (context_words=[kitchen])","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":19,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:31:57.990Z"}
{"instant":{"epochSecond":1646343148,"nanoOfSecond":91000000},"thread":"grpc-default-executor-0","level":"INFO","loggerName":"hipstershop.AdService","message":"received ad request (context_words=[footwear])","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":18,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:32:28.091Z"}
{"instant":{"epochSecond":1646343148,"nanoOfSecond":797000000},"thread":"grpc-default-executor-0","level":"INFO","loggerName":"hipstershop.AdService","message":"received ad request (context_words=[footwear])","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","threadId":18,"threadPriority":5,"logging.googleapis.com/trace":"00000000000000000000000000000000","logging.googleapis.com/spanId":"0000000000000000","logging.googleapis.com/traceSampled":"false","time":"2022-03-03T21:32:28.797Z"}

ksingh7 avatar Mar 03 '22 21:03 ksingh7

@NimJay can you please re-open this issue. Thanks

ksingh7 avatar Mar 03 '22 21:03 ksingh7

You shouldn't need to add any GCP creds to get any of the services working. @NimJay could you take a look and see if perhaps the adservice is malfunctioning when running outside e.g. GKE?

bourgeoisor avatar Mar 03 '22 23:03 bourgeoisor

Hi @ksingh7, sorry for the delay on this.

Just curious, how do you deploy the Online Boutique apps? With the manifests in release/ folder?

Could you confirm that you have removed the DISABLE_STATS and DISABLE_TRACING environment variables in the adservice's Deployment manifest?

mathieu-benoit avatar Oct 03 '22 14:10 mathieu-benoit

@ksingh7 can you provide the feedback to these questions pls?

minherz avatar Dec 15 '22 22:12 minherz

Closing this issue as we haven't received answers for Mathieu's questions.

NimJay avatar Feb 15 '23 13:02 NimJay