Analyzing Cloud Controller's NGINX logs using the toplogs script

What is toplogs?

The toplogs-cloudcontroller.sh script is a community maintained script that we've found useful for quickly making sense of a Cloud Controller's nginx-access.log.

Running toplogs locally

1. Download the script and make it executable

wget https://raw.githubusercontent.com/dmikusa-pivotal/cf-debug-tools/8ede2d54b83b1e1409509241ae42abe67d6a4603/toplogs-cloudcontroller.sh
chmod +x 
chmod +x toplogs-cloudcontroller.sh

2. Download logs from the api VMs

bosh logs api

3. Untar the log files

mkdir cc-logs
tar -xzvf cf.api-20190506-172436-254239.tgz -C cc-logs/

4. Run the script against the nginx-access.log files

./toplogs-cloudcontroller.sh cc-logs/cloud_controller_ng/nginx-access.log

Running toplogs on a Cloud Controller vm

1. bosh ssh api/0
2. Download the toplogs-cloudcontroller.sh script and make it executable

wget https://raw.githubusercontent.com/dmikusa-pivotal/cf-debug-tools/8ede2d54b83b1e1409509241ae42abe67d6a4603/toplogs-cloudcontroller.sh -O /tmp/toplogs-cloudcontroller.sh

chmod +x /tmp/toplogs-cloudcontroller.sh

3. Run toplogs-cloudcontroller.sh against one or more nginx-access.log files

/tmp/toplogs-cloudcontroller.sh /var/vcap/sys/log/cloud_controller_ng/nginx-access.log

Example output

Here is some example output from a lightly used bosh-lite test environment:

--------------------------------------
  Duration
--------------------------------------

07/May/2019 00:18:55
07/May/2019 00:24:26

--------------------------------------
  Response Codes
--------------------------------------

 110 200
   1 302

--------------------------------------
  Request Methods
--------------------------------------

 108 GET
   3 POST

--------------------------------------
  Top 10 Requests (no query params)
--------------------------------------

  67 /v2/info
  23 /internal/v4/syslog_drain_urls
   4 /v2/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593/instances
   4 /v2/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593
   1 /v3/processes/5923b69b-54e6-4e69-be0a-a7c0b91ed593/stats
   1 /v3/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593/processes/web
   1 /v3/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593/processes
   1 /v3/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593/droplets/current
   1 /v3/apps
   1 /v2/shared_domains/2429bb4d-2517-4757-bee4-7a7e948bb449

--------------------------------------
  Top 10 Requests (with query params)
--------------------------------------

  67 /v2/info
  23 /internal/v4/syslog_drain_urls?batch_size=1000&next_id=0
   4 /v2/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593/instances
   4 /v2/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593
   1 /v3/processes/5923b69b-54e6-4e69-be0a-a7c0b91ed593/stats
   1 /v3/apps?names=dora&space_guids=cce5fc71-0fe3-48fe-8cfe-e1b013a35466
   1 /v3/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593/processes/web
   1 /v3/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593/processes
   1 /v3/apps/5923b69b-54e6-4e69-be0a-a7c0b91ed593/droplets/current
   1 /v2/shared_domains/2429bb4d-2517-4757-bee4-7a7e948bb449

--------------------------------------
  Top 10 User Agents
--------------------------------------

  34 curl/7.47.0
  33 monit/5.2.5
  28 Go-http-client/1.1
  16 cf/6.44.0+5de0f0d02.2019-05-01 (go1.12.1; amd64 darwin)

--------------------------------------
  Top 10 Referrers
--------------------------------------

 111 -

--------------------------------------
  Top 10 Forwarded IPs
--------------------------------------

  36 10.244.0.134
  34 127.0.0.1
  23 10.244.0.136
  16 76.126.189.229, 10.244.0.34
   1 10.244.0.139
   1 10.244.0.131

--------------------------------------
  Top 10 Direct Client IP
--------------------------------------

  34 localhost
  33 10.244.0.134
  28 cloud-controller-ng.service.cf.internal
  16 api.bird-seer.capi.land

--------------------------------------
  Top 10 Days
--------------------------------------

 111 07/May/2019

--------------------------------------
  Top 10 Hours
--------------------------------------

 111 07/May/2019 00

--------------------------------------
  Top 10 Minutes
--------------------------------------

  35 07/May/2019 00:19
  16 07/May/2019 00:23
  16 07/May/2019 00:22
  16 07/May/2019 00:21
  16 07/May/2019 00:20
   8 07/May/2019 00:24
   4 07/May/2019 00:18

--------------------------------------
  Top 10 Seconds
--------------------------------------

  11 07/May/2019 00:19:11
   4 07/May/2019 00:19:04
   3 07/May/2019 00:19:01
   2 07/May/2019 00:18:55
   1 07/May/2019 00:24:26
   1 07/May/2019 00:24:25
   1 07/May/2019 00:24:24
   1 07/May/2019 00:24:15
   1 07/May/2019 00:24:14
   1 07/May/2019 00:24:11

--------------------------------------
  Top 10 Response Times (secs)
--------------------------------------

 111 0