deis / logger

In-memory log buffer used by Deis Workflow.
https://deis.com
MIT License
18 stars 15 forks source link

Application logs not showing in deis logs on Google Container Engine #116

Closed finseth closed 7 years ago

finseth commented 7 years ago

Replicate the issue by following the install instructions for Google Container Engine (https://deis.com/docs/workflow/quickstart/provider/gke/install-gke/)

Clone and push the example-nodejs-express repo (https://github.com/deis/example-nodejs-express)

deis logs
FO [demo]: config demo-c610877 updated
INFO [demo]: admin created initial release
INFO [demo]: appsettings demo-e04a0ae updated
INFO [demo]: domain demo added
INFO [demo]: build demo-f06ae47 created
INFO [demo]: admin deployed 9287d04
INFO [demo]: buildpack type detected. Defaulting to $PORT 5000
INFO [demo]: adding 30s on to the original 120s timeout to account for the initial delay specified in the liveness / readiness probe
INFO [demo]: This deployments overall timeout is 150s - batch timout is 150s and there are 1 batches to deploy with a total of 1 pods
INFO [demo]: waited 10s and 1 pods are in service
INFO [demo]: waited 20s and 1 pods are in service
INFO [demo]: waited 30s and 1 pods are in service

'deis logs' fails to output the expected 'Server listening on port 5000 in production mode'

jchauncey commented 7 years ago

Try the following:

kubectl get pods --all-namespaces
kubectl get  logs --namespace=<app-namespace> <podid>

See if you see the log statements appear there.

finseth commented 7 years ago
>_ kubectl get pods --all-namespaces
NAMESPACE     NAME                                                             READY     STATUS    RESTARTS   AGE
deis          deis-builder-4144344535-m2igv                                    1/1       Running   2          10h
deis          deis-controller-3764676435-j8iau                                 1/1       Running   2          10h
deis          deis-database-nw17y                                              1/1       Running   0          10h
deis          deis-logger-d91ez                                                1/1       Running   3          10h
deis          deis-logger-fluentd-3csye                                        1/1       Running   0          10h
deis          deis-logger-fluentd-fshpk                                        1/1       Running   0          10h
deis          deis-logger-redis-22gsq                                          1/1       Running   0          10h
deis          deis-minio-2c65g                                                 1/1       Running   0          10h
deis          deis-monitor-grafana-xai4b                                       1/1       Running   0          10h
deis          deis-monitor-influxdb-3ktnb                                      1/1       Running   0          10h
deis          deis-monitor-telegraf-b1aci                                      1/1       Running   0          10h
deis          deis-monitor-telegraf-w1jx3                                      1/1       Running   1          10h
deis          deis-nsqd-jd6fg                                                  1/1       Running   0          10h
deis          deis-registry-3928253639-39530                                   1/1       Running   4          10h
deis          deis-registry-proxy-6l4x4                                        1/1       Running   0          10h
deis          deis-registry-proxy-yx5ma                                        1/1       Running   0          10h
deis          deis-router-1715979499-bll59                                     1/1       Running   0          10h
deis          deis-workflow-manager-2972479182-dfu6a                           1/1       Running   0          10h
demo          demo-web-1800750201-yxn5p                                        1/1       Running   0          9h
kube-system   fluentd-cloud-logging-gke-cluster-1-default-pool-667bdfc5-4k6y   1/1       Running   0          10h
kube-system   fluentd-cloud-logging-gke-cluster-1-default-pool-667bdfc5-iqrf   1/1       Running   0          10h
kube-system   heapster-v1.1.0-2599329277-a9tzx                                 2/2       Running   0          10h
kube-system   kube-dns-v17.1-6huyb                                             3/3       Running   0          10h
kube-system   kube-dns-v17.1-dft8q                                             3/3       Running   0          10h
kube-system   kube-proxy-gke-cluster-1-default-pool-667bdfc5-4k6y              1/1       Running   0          10h
kube-system   kube-proxy-gke-cluster-1-default-pool-667bdfc5-iqrf              1/1       Running   0          10h
kube-system   kubernetes-dashboard-v1.1.1-uza6j                                1/1       Running   0          10h
kube-system   l7-default-backend-v1.0-aywqz                                    1/1       Running   0          10h
>_ kubectl get logs --namespace=demo demo-web-1800750201-yxn5p
the server doesn't have a resource type "logs"
jchauncey commented 7 years ago

Sorry I didn't mean get logs. Just kubectl logs

On Sep 16, 2016 6:45 AM, "finseth" notifications@github.com wrote:

_ kubectl get pods --all-namespaces NAMESPACE NAME READY STATUS RESTARTS AGE deis deis-builder-4144344535-m2igv 1/1 Running 2 10h deis deis-controller-3764676435-j8iau 1/1 Running 2 10h deis deis-database-nw17y 1/1 Running 0 10h deis deis-logger-d91ez 1/1 Running 3 10h deis deis-logger-fluentd-3csye 1/1 Running 0 10h deis deis-logger-fluentd-fshpk 1/1 Running 0 10h deis deis-logger-redis-22gsq 1/1 Running 0 10h deis deis-minio-2c65g 1/1 Running 0 10h deis deis-monitor-grafana-xai4b 1/1 Running 0 10h deis deis-monitor-influxdb-3ktnb 1/1 Running 0 10h deis deis-monitor-telegraf-b1aci 1/1 Running 0 10h deis deis-monitor-telegraf-w1jx3 1/1 Running 1 10h deis deis-nsqd-jd6fg 1/1 Running 0 10h deis deis-registry-3928253639-39530 1/1 Running 4 10h deis deis-registry-proxy-6l4x4 1/1 Running 0 10h deis deis-registry-proxy-yx5ma 1/1 Running 0 10h deis deis-router-1715979499-bll59 1/1 Running 0 10h deis deis-workflow-manager-2972479182-dfu6a 1/1 Running 0 10h demo demo-web-1800750201-yxn5p 1/1 Running 0 9h kube-system fluentd-cloud-logging-gke-cluster-1-default-pool-667bdfc5-4k6y 1/1 Running 0 10h kube-system fluentd-cloud-logging-gke-cluster-1-default-pool-667bdfc5-iqrf 1/1 Running 0 10h kube-system heapster-v1.1.0-2599329277-a9tzx 2/2 Running 0 10h kube-system kube-dns-v17.1-6huyb 3/3 Running 0 10h kube-system kube-dns-v17.1-dft8q 3/3 Running 0 10h kube-system kube-proxy-gke-cluster-1-default-pool-667bdfc5-4k6y 1/1 Running 0 10h kube-system kube-proxy-gke-cluster-1-default-pool-667bdfc5-iqrf 1/1 Running 0 10h kube-system kubernetes-dashboard-v1.1.1-uza6j 1/1 Running 0 10h kube-system l7-default-backend-v1.0-aywqz 1/1 Running 0 10h

_ kubectl get logs --namespace=demo demo-web-1800750201-yxn5p the server doesn't have a resource type "logs"

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/deis/logger/issues/116#issuecomment-247571355, or mute the thread https://github.com/notifications/unsubscribe-auth/AAaRGODqb7-TuNIqTGL64bQcu0gYPjlxks5qqnMygaJpZM4J-hjj .

finseth commented 7 years ago
>_ kubectl logs --namespace=demo demo-web-1800750201-yxn5p
Server listening on port 5000 in production mode

There we go

jchauncey commented 7 years ago

Does it appear in deis logs yet?

On Sep 16, 2016 7:21 AM, "finseth" notifications@github.com wrote:

_ kubectl logs --namespace=demo demo-web-1800750201-yxn5p Server listening on port 5000 in production mode

There we go

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/deis/logger/issues/116#issuecomment-247577105, or mute the thread https://github.com/notifications/unsubscribe-auth/AAaRGBMF1Riq-x_KnAq5aohjVbYZ52s8ks5qqnuvgaJpZM4J-hjj .

finseth commented 7 years ago

no, still nothing

jchauncey commented 7 years ago

try the following

kubectl exec --namespace=deis <fluentd pod id> ls /var/log/containers

See if the container log files appear

finseth commented 7 years ago

Looks like the log files are present

...
slugbuild-demo-87e55fbd-20988653_deis_POD-046a5146cd4bdc5732352adb3bd30c0f7f123c0fc2c0011468352be3e88dd452.log
slugbuild-demo-87e55fbd-20988653_deis_deis-slugbuilder-dfc235ada5c520195e250682442ed0579a812a4097f5fb1b4fbc2df44a3e5a52.log
slugbuild-demo-9287d045-45c57f07_deis_POD-36e09b06e012932d584638feea0bca3d23675e8c0cfb8a4a63cff2c4d3cce47a.log
slugbuild-demo-9287d045-45c57f07_deis_deis-slugbuilder-8c24a1ddc60d3c2a7d451805abb2ad16834af51273ef3b0de6a0813c6fab7601.log
...
jchauncey commented 7 years ago

If you go to grafana.yourdomain.com and login using admin/admin or whatever you set the username/password to be. Look at the NSQ health dashboard. Do you see the logging queue backing up?

I'm not actually sure why you aren't seeing any application logs.

Have you tried getting your app to generate more logs and see if they appear?

finseth commented 7 years ago

Everything looks normal in Grafana. I modified the example code to produce extra logs and they all show up so I guess the issue is contained to the first few lines of the application log not showing.

jchauncey commented 7 years ago

it might have been a race condition or something whompy with the message we received. if you are seeing log messages now i will close this issue.

finseth commented 7 years ago

yep, thanks for the help