Readct credentials in logs

src/bosh_azure_cpi/lib/cloud/azure/azure_client2.rb

@@ -49,6 +49,9 @@ class AzureClient2
     REST_API_PROVIDER_STORAGE            = 'Microsoft.Storage'
     REST_API_STORAGE_ACCOUNTS            = 'storageAccounts'
 
+    # Please add the key into this list if you want to redact its value in request body.
+    CREDENTIAL_KEYWORD_LIST = ['adminPassword', 'client_secret']
+
     def initialize(azure_properties, logger)
       @logger = logger
 
@@ -1398,7 +1401,7 @@ def create_storage_account(name, location, account_type, tags)
       request_body = storage_account.to_json
       request.body = request_body
       request['Content-Length'] = request_body.size
-      @logger.debug("create_storage_account - request body:\n#{request.body}")
+      @logger.debug("create_storage_account - request body:\n#{redact_credentials_in_request_body(storage_account)}")
 
       retry_after = 10
       response = http_get_response(uri, request, retry_after)
@@ -1683,12 +1686,20 @@ def parse_public_ip(result)
     end
 
     def filter_credential_in_logs(uri)
-      if uri.request_uri.include?('/listKeys')
+      if !is_debug_mode(@azure_properties) && uri.request_uri.include?('/listKeys')
         return true
       end
       false
     end
 
+    def redact_credentials(keys, hash)
+      Hash[hash.map { |k,v| [k, v.kind_of?(Hash) ? redact_credentials(keys, v) : (keys.include?(k) ? '<redacted>' : v) ] }]
+    end
+
+    def redact_credentials_in_request_body(body)
+      is_debug_mode(@azure_properties) ? body.to_json : redact_credentials(CREDENTIAL_KEYWORD_LIST, body).to_json
+    end
+
     def http(uri)
       http = Net::HTTP.new(uri.host, uri.port)
       http.use_ssl = true
@@ -1730,6 +1741,7 @@ def get_token(force_refresh = false)
           request.body = URI.encode_www_form(params)
           @logger.debug("get_token - request.header:")
           request.each_header { |k,v| @logger.debug("\t#{k} = #{v}") }
+          @logger.debug("get_token - request body:\n#{redact_credentials_in_request_body(params)}")
 
           response = http(uri).request(request)
         rescue Net::OpenTimeout, Net::ReadTimeout, Errno::ECONNRESET => e
@@ -1969,7 +1981,7 @@ def http_put(url, body = nil, params = {}, retry_after = 5)
           request_body = body.to_json
           request.body = request_body
           request['Content-Length'] = request_body.size
-          @logger.debug("http_put - request body:\n#{request.body}")
+          @logger.debug("http_put - request body:\n#{redact_credentials_in_request_body(body)}")
         end
 
         response = http_get_response(uri, request, retry_after)
@@ -2002,7 +2014,7 @@ def http_patch(url, body = nil, params = {}, retry_after = 5)
           request_body = body.to_json
           request.body = request_body
           request['Content-Length'] = request_body.size
-          @logger.debug("http_patch - request body:\n#{request.body}")
+          @logger.debug("http_patch - request body:\n#{redact_credentials_in_request_body(body)}")
         end
 
         response = http_get_response(uri, request, retry_after)
@@ -2062,7 +2074,7 @@ def http_post(url, body = nil, params = {}, retry_after = 5)
           request_body = body.to_json
           request.body = request_body
           request['Content-Length'] = request_body.size
-          @logger.debug("http_put - request body:\n#{request.body}")
+          @logger.debug("http_put - request body:\n#{redact_credentials_in_request_body(body)}")
         end
         response = http_get_response(uri, request, retry_after)
         options = {

src/bosh_azure_cpi/lib/cloud/azure/cloud.rb

@@ -120,7 +120,8 @@ def delete_stemcell(stemcell_id)
     # @return [String] opaque id later used by {#configure_networks}, {#attach_disk},
     #                  {#detach_disk}, and {#delete_vm}
     def create_vm(agent_id, stemcell_id, resource_pool, networks, disk_locality = nil, env = nil)
-      @logger.info("create_vm(#{agent_id}, #{stemcell_id}, #{resource_pool}, #{networks}, #{disk_locality}, #{env})")
+      # env may contain credentials so we must not log it
+      @logger.info("create_vm(#{agent_id}, #{stemcell_id}, #{resource_pool}, #{networks}, #{disk_locality}, ...)")
       with_thread_name("create_vm(#{agent_id}, ...)") do
         if @use_managed_disks
           instance_id = agent_id

src/bosh_azure_cpi/lib/cloud/azure/vm_manager.rb

@@ -13,7 +13,8 @@ def initialize(azure_properties, registry_endpoint, disk_manager, disk_manager2,
     end
 
     def create(instance_id, location, stemcell_info, resource_pool, network_configurator, env)
-      @logger.info("create(#{instance_id}, #{location}, #{stemcell_info.inspect}, #{resource_pool}, #{network_configurator.inspect}, #{env})")
+      # network_configurator contains service principal in azure_properties so we must not log it.
+      @logger.info("create(#{instance_id}, #{location}, #{stemcell_info.inspect}, #{resource_pool}, ..., ...)")
 
       vm_size = resource_pool.fetch('instance_type', nil)
       cloud_error("missing required cloud property `instance_type'.") if vm_size.nil?

src/bosh_azure_cpi/spec/unit/azure_client2/create_virtual_machine_spec.rb

@@ -828,14 +828,16 @@
       end
 
       context "when os_type is windows" do
+        let(:logger_strio) { StringIO.new }
+        let(:windows_password) { 'THISISWINDOWSCREDENTIAL' }
         let(:vm_params) do
           {
             :name               => vm_name,
             :location           => "b",
             :tags               => { "foo" => "bar"},
             :vm_size            => "c",
             :windows_username   => "d",
-            :windows_password   => "e",
+            :windows_password   => windows_password,
             :custom_data        => "f",
             :image_uri          => "g",
             :os_disk            => {
@@ -865,7 +867,7 @@
                 :customData => "f",
                 :computerName => vm_name,
                 :adminUsername => "d",
-                :adminPassword => "e",
+                :adminPassword => windows_password,
                 :windowsConfiguration => {
                   :enableAutomaticUpdates => false
                 }
@@ -905,28 +907,80 @@
           }
         }
 
-        it "should raise no error" do
-          stub_request(:post, token_uri).to_return(
-            :status => 200,
-            :body => {
-              "access_token" => valid_access_token,
-              "expires_on" => expires_on
-            }.to_json,
-            :headers => {})
-          stub_request(:put, vm_uri).with(body: request_body).to_return(
-            :status => 200,
-            :body => '',
-            :headers => {
-              "azure-asyncoperation" => operation_status_link
-            })
-          stub_request(:get, operation_status_link).to_return(
-            :status => 200,
-            :body => '{"status":"Succeeded"}',
-            :headers => {})
+        context "redact credentials in logs" do
+          let(:azure_client2) {
+            Bosh::AzureCloud::AzureClient2.new(
+              mock_cloud_options["properties"]["azure"],
+              Logger.new(logger_strio)
+            )
+          }
 
-          expect {
-            azure_client2.create_virtual_machine(vm_params, network_interfaces)
-          }.not_to raise_error
+          it "should raise no error" do
+            stub_request(:post, token_uri).to_return(
+              :status => 200,
+              :body => {
+                "access_token" => valid_access_token,
+                "expires_on" => expires_on
+              }.to_json,
+              :headers => {})
+            stub_request(:put, vm_uri).with(body: request_body).to_return(
+              :status => 200,
+              :body => '',
+              :headers => {
+                "azure-asyncoperation" => operation_status_link
+              })
+            stub_request(:get, operation_status_link).to_return(
+              :status => 200,
+              :body => '{"status":"Succeeded"}',
+              :headers => {})
+
+            expect {
+              azure_client2.create_virtual_machine(vm_params, network_interfaces)
+            }.not_to raise_error
+
+            logs = logger_strio.string
+            expect(logs.include?(windows_password)).to be(false)
+            expect(logs.include?(MOCK_AZURE_CLIENT_SECRET)).to be(false)
+            expect(logs.scan('<redacted>').count).to eq(2)
+          end
+        end
+
+        context "do not redact credentials in logs" do
+          let(:azure_client2) {
+            Bosh::AzureCloud::AzureClient2.new(
+              mock_cloud_options["properties"]["azure"].merge({ 'debug_mode' => true }),
+              Logger.new(logger_strio)
+            )
+          }
+
+          it "should raise no error" do
+            stub_request(:post, token_uri).to_return(
+              :status => 200,
+              :body => {
+                "access_token" => valid_access_token,
+                "expires_on" => expires_on
+              }.to_json,
+              :headers => {})
+            stub_request(:put, vm_uri).with(body: request_body).to_return(
+              :status => 200,
+              :body => '',
+              :headers => {
+                "azure-asyncoperation" => operation_status_link
+              })
+            stub_request(:get, operation_status_link).to_return(
+              :status => 200,
+              :body => '{"status":"Succeeded"}',
+              :headers => {})
+
+            expect {
+              azure_client2.create_virtual_machine(vm_params, network_interfaces)
+            }.not_to raise_error
+
+            logs = logger_strio.string
+            expect(logs.include?(windows_password)).to be(true)
+            expect(logs.include?(MOCK_AZURE_CLIENT_SECRET)).to be(true)
+            expect(logs.include?('<redacted>')).to be(false)
+          end
         end
       end
 

src/bosh_azure_cpi/spec/unit/azure_client2/get_operation_spec.rb

@@ -270,6 +270,8 @@
     }
   }
 
+  let(:storage_account_name) { "fake-name" }
+
   before do
     stub_request(:post, token_uri).to_return(
       :status => 200,
@@ -423,7 +425,6 @@
   end
 
   describe "#get_storage_account_by_name" do
-    let(:storage_account_name) { "foo" }
     let(:storage_account_uri) { "https://management.azure.com//subscriptions/#{subscription_id}/resourceGroups/#{resource_group_name}/providers/Microsoft.Storage/storageAccounts/#{storage_account_name}?api-version=#{api_version}" }
 
     context "if get operation returns retryable error code (returns 429)" do
@@ -1106,4 +1107,85 @@
       end
     end
   end
+
+  describe "#get_storage_account_keys_by_name" do
+    let(:storage_account_list_keys_uri) { "https://management.azure.com//subscriptions/#{subscription_id}/resourceGroups/#{resource_group_name}/providers/Microsoft.Storage/storageAccounts/#{storage_account_name}/listKeys?api-version=#{api_version}" }
+    let(:storage_account_list_keys_response_body) {
+      {
+        "key1" => "fake-key-1",
+        "key2" => "fake-key-2"
+      }.to_json
+    }
+    let(:fake_keys) {
+      [
+        "fake-key-1",
+        "fake-key-2"
+      ]
+    }
+
+    context "when token is valid but cannot find the storage account" do
+      it "should return []" do
+        stub_request(:post, storage_account_list_keys_uri).to_return(
+          :status => 404,
+          :body => '',
+          :headers => {})
+
+        expect(
+          azure_client2.get_storage_account_keys_by_name(storage_account_name)
+        ).to eq([])
+      end
+    end
+
+    context "when token is valid, getting response succeeds" do
+      let(:logger_strio) { StringIO.new }
+
+      context "and debug_mode is set to false" do
+        let(:azure_client2) {
+          Bosh::AzureCloud::AzureClient2.new(
+            mock_cloud_options["properties"]["azure"],
+            Logger.new(logger_strio)
+          )
+        }
+
+        it "should return keys and filter keys in logs" do
+          stub_request(:post, storage_account_list_keys_uri).to_return(
+            :status => 200,
+            :body => storage_account_list_keys_response_body,
+            :headers => {})
+
+          expect(
+            azure_client2.get_storage_account_keys_by_name(storage_account_name)
+          ).to eq(fake_keys)
+
+          logs = logger_strio.string
+          expect(logs.include?('fake-key-1')).to be(false)
+          expect(logs.include?('fake-key-2')).to be(false)
+        end
+      end
+
+      context "and debug_mode is set to true" do
+        let(:azure_client2) {
+          Bosh::AzureCloud::AzureClient2.new(
+            mock_cloud_options["properties"]["azure"].merge({ 'debug_mode' => true }),
+            Logger.new(logger_strio)
+          )
+        }
+
+        it "should return keys and log keys" do
+          stub_request(:post, storage_account_list_keys_uri).to_return(
+            :status => 200,
+            :body => storage_account_list_keys_response_body,
+            :headers => {})
+
+          expect(
+            azure_client2.get_storage_account_keys_by_name(storage_account_name)
+          ).to eq(fake_keys)
+
+          logs = logger_strio.string
+          expect(logs.include?('fake-key-1')).to be(true)
+          expect(logs.include?('fake-key-2')).to be(true)
+        end
+      end
+    end
+  end
 end