How to enable request logging from cloud controller to external blobstore?
search cancel

How to enable request logging from cloud controller to external blobstore?

book

Article ID: 297737

calendar_today

Updated On:

Products

VMware Tanzu Application Service for VMs

Issue/Introduction

To check HTTP requests/responses between cloud controller and external Blobstore. 

This KB will cover S3-Compatible Blobstores, and GCP & Azure Blobstores.

Environment


Resolution

To enable EXCON_DEBUG on a single cloud controller, follow the steps listed below:

  • SSH to cloud controller
  • For S3-Compatible Blobstores,
    • Add export EXCON_DEBUG=true into file /var/vcap/jobs/cloud_controller_ng/bin/cloud_controller_ng
  • For GCP & Azure Blobstores,
    • Add export DEBUG=true into file /var/vcap/jobs/cloud_controller_ng/bin/cloud_controller_ng
  • monit restart cloud_controller_ng
Note: You will see requests and responses as below

In /var/vcap/sys/log/cloud_controller_ng/cloud_controller_ng.stderr.log or cloud_controller_ng_ctl.err.log (if this is a GCP or Azure Blobstore, formatting will be slightly different). 
 [2019-07-05 01:20:56+0000] excon.request
 [2019-07-05 01:20:56+0000]   :chunk_size          => 1048576
 [2019-07-05 01:20:56+0000]   :ciphers             => "ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256: DHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA :DHE-RSA-AES256-SHA256:DHE-RSA-AES256-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA:!DSS"
 [2019-07-05 01:20:56+0000]   :connect_timeout     => 60
 [2019-07-05 01:20:56+0000]   :debug_request       => true
 [2019-07-05 01:20:56+0000]   :debug_response      => true
 [2019-07-05 01:20:56+0000]   :expects             => 200
 [2019-07-05 01:20:56+0000]   :headers             => {
 [2019-07-05 01:20:56+0000]     "Authorization" => "REDACTED"
 [2019-07-05 01:20:56+0000]     "Date"          => "Fri, 05 Jul 2019 01:20:56 +0000"
 [2019-07-05 01:20:56+0000]     "Host"          => "test.local"
 [2019-07-05 01:20:56+0000]     "User-Agent"    => "fog-core/1.43.0"
 [2019-07-05 01:20:56+0000]   }
 [2019-07-05 01:20:56+0000]   :host                => "test.local"
 [2019-07-05 01:20:56+0000]   :hostname            => "test.local"
 [2019-07-05 01:20:56+0000]   :idempotent          => true
 [2019-07-05 01:20:56+0000]   :instrumentor        => Excon::StandardInstrumentor
 [2019-07-05 01:20:56+0000]   :instrumentor_name   => "excon"
 [2019-07-05 01:20:56+0000]   :method              => "GET"
 [2019-07-05 01:20:56+0000]   :middlewares         => [
 [2019-07-05 01:20:56+0000]     Excon::Middleware::ResponseParser
 [2019-07-05 01:20:56+0000]     Excon::Middleware::Expects
 [2019-07-05 01:20:56+0000]     Excon::Middleware::Idempotent
 [2019-07-05 01:20:56+0000]     Excon::Middleware::Instrumentor
 [2019-07-05 01:20:56+0000]     Excon::Middleware::Mock
 [2019-07-05 01:20:56+0000]   ]
 [2019-07-05 01:20:56+0000]   :mock                => false
 [2019-07-05 01:20:56+0000]   :nonblock            => true
 [2019-07-05 01:20:56+0000]   :omit_default_port   => false
 [2019-07-05 01:20:56+0000]   :path                => "/resources/"
 [2019-07-05 01:20:56+0000]   :persistent          => false
 [2019-07-05 01:20:56+0000]   :port                => 9020
 [2019-07-05 01:20:56+0000]   :query               => {
 [2019-07-05 01:20:56+0000]     "max-keys" => 1
 [2019-07-05 01:20:56+0000]   }
 [2019-07-05 01:20:56+0000]   :read_timeout        => nil
 [2019-07-05 01:20:56+0000]   :response_block      => #<Proc:0x00005622f1a67e70@/var/vcap/packages/cloud_controller_ng/cloud_controller_ng/vendor/bundle/ruby/2.4.0/gems/fog-xml-0.1.3/lib/fog/xml/sax_parser_connection.rb:29 (lambda)>
 [2019-07-05 01:20:56+0000]   :retries_remaining   => 4
 [2019-07-05 01:20:56+0000]   :retry_limit         => 4
 [2019-07-05 01:20:56+0000]   :scheme              => "http"
 [2019-07-05 01:20:56+0000]   :ssl_uri_schemes     => [
 [2019-07-05 01:20:56+0000]     "https"
 [2019-07-05 01:20:56+0000]   ]
 [2019-07-05 01:20:56+0000]   :ssl_verify_peer     => true
 [2019-07-05 01:20:56+0000]   :stubs               => :global
 [2019-07-05 01:20:56+0000]   :tcp_nodelay         => false
 [2019-07-05 01:20:56+0000]   :thread_safe_sockets => true
 [2019-07-05 01:20:56+0000]   :uri_parser          => URI
 [2019-07-05 01:20:56+0000]   :versions            => "excon/0.62.0 (x86_64-linux) ruby/2.4.2"
 [2019-07-05 01:20:56+0000]   :write_timeout       => nil
......
 [2019-07-05 01:20:56+0000] excon.retry
......
 [2019-07-05 01:20:56+0000] excon.response
 [2019-07-05 01:20:56+0000]   :body          => ""
 [2019-07-05 01:20:56+0000]   :cookies       => [
 [2019-07-05 01:20:56+0000]   ]
 [2019-07-05 01:20:56+0000]   :headers       => {
 [2019-07-05 01:20:56+0000]     "Content-Length"         => "641"
 [2019-07-05 01:20:56+0000]     "Content-Type"           => "application/xml"
 [2019-07-05 01:20:56+0000]     "Date"                   => "Fri, 05 Jul 2019 01:20:56 GMT"
 [2019-07-05 01:20:56+0000]     "Server"                 => "ViPR/1.0"
 [2019-07-05 01:20:56+0000]     "x-amz-id-2"             => "35ecb81c8d6aa9b9172847b48f46291ec4ac229e96add57e205e086e389c3ab3"
 [2019-07-05 01:20:56+0000]     "x-amz-request-id"       => "0ae4fa8d:168cc80f6b0:72669:7"
 [2019-07-05 01:20:56+0000]     "x-emc-retention-period" => "10"
 [2019-07-05 01:20:56+0000]   }
 [2019-07-05 01:20:56+0000]   :host          => "test.local"
 [2019-07-05 01:20:56+0000]   :local_address => "10.100.5.36"
 [2019-07-05 01:20:56+0000]   :local_port    => 42722
 [2019-07-05 01:20:56+0000]   :path          => "/resources/"
 [2019-07-05 01:20:56+0000]   :port          => 9020
 [2019-07-05 01:20:56+0000]   :reason_phrase => "OK"
 [2019-07-05 01:20:56+0000]   :remote_ip     => "192.168.8.10"
 [2019-07-05 01:20:56+0000]   :status        => 200
 [2019-07-05 01:20:56+0000]   :status_line   => "HTTP/1.1 200 OK\r\n"

To enable EXCON_DEBUG on all cloud controllers talking to your S3-Compatible Blobstore, use the following steps as written. If your Blobstore is on GCP or Azure, replace EXCON_DEBUG with DEBUG for the following steps:

  • Verify if EXCON_DEBUG has already been enabled.
bosh -d <CF-DEPLOYMENT> ssh cloud_controller -c "cd /var/vcap/jobs/cloud_controller_ng/bin/; cat cloud_controller_ng"
  • Insert export EXCON_DEBUG=true. Notice that we are matching the start command of cloud controller with pattern exec /var/vcap/packages/cloud_controller_ng/cloud_controller_ng/bin/cloud_controller.
  • In future TAS versions, if the start command of cloud controller changes, you need to modify this step accordingly.
bosh -d <CF-DEPLOYMENT> ssh cloud_controller -c "cd /var/vcap/jobs/cloud_controller_ng/bin/; sudo sed -i '/exec \/var\/vcap\/packages\/cloud_controller_ng\/cloud_controller_ng\/bin\/cloud_controller/i export EXCON_DEBUG=true' cloud_controller_ng; cat cloud_controller_ng"
  • Restart all cloud controllers.
bosh -d <CF-DEPLOYMENT> ssh cloud_controller -c "sudo /var/vcap/bosh/bin/monit restart cloud_controller_ng"

To disable EXCON_DEBUG on all cloud controllers.

  • Revert the change.
bosh -d <CF-DEPLOYMENT> ssh cloud_controller -c "cd /var/vcap/jobs/cloud_controller_ng/bin/; sudo sed -i '/EXCON_DEBUG/d' cloud_controller_ng; cat cloud_controller_ng"
  • Restart all cloud controllers.
bosh -d <CF-DEPLOYMENT> ssh cloud_controller -c "sudo /var/vcap/bosh/bin/monit restart cloud_controller_ng"


Additional Information

1. Summary of environment variables to enable request logging.
 
Blobstore TypeEnvironment Variable to use:
S3-CompatibleEXCON_DEBUG
AzureDEBUG
GCPDEBUG

If you do not see your Blobstore type in this KB, then unfortunately we cannot enable Request Logging to your Blobstore at this time.

2. Since TAS v2.6, there is a script available in cloud controller which can be used to benchmark blobstore performance. 
# ssh to one cloud controller VM

sudo /var/vcap/jobs/cloud_controller_ng/bin/perform_blobstore_benchmarks
3. Instead of enabling request logging, it would be more straightforward to capture traffic via tcpdump in some problem scenarios, e.g., when suspecting network latency between cloud controller and blobstore. A traffic dump may unveil underlying issue at network layer which is not directly observable in request logging.

Powered by Wolken Software