Repository: Azure/WALinuxAgent

Issue:
[2.2.14] HostGAPlugin still use proxy while auto-updating
Hi there,

I saw there was an issue #769 "HostGAPlugin requests should never go through proxy". But currently it seems that only the blob status upload traffic can ignore the proxy when proxy is misconfigured. For the auto-update feature, only the manifest file can be downloaded without proxy, the WALA update packages still use proxy and fail to be downloaded. The extension downloading process is the same as auto-update. Is it by design? Thanks! 

My steps:
1. Configure /etc/waagent.conf to set a wrong proxy, enable auto-update, and enable verbose log:
HttpProxy.Host=172.16.0.1
HttpProxy.Port=3128
Logs.Verbose=y
AutoUpdate.Enabled=y
Service waagent restart
2. Check /var/log/waagent.log
```
2017/07/12 06:29:39.476351 VERBOSE HTTP proxy: [172.16.0.1:3128]
2017/07/12 06:29:39.483259 VERBOSE HTTP connection [GET] [http://rdfepirv2sg1prdstr03.blob.core.windows.net:80/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml] [None] [None]
2017/07/12 06:29:49.513148 VERBOSE HTTP connection [GET] [http://rdfepirv2sg1prdstr03.blob.core.windows.net:80/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml] [None] [None]
2017/07/12 06:29:59.547066 VERBOSE HTTP connection [GET] [http://rdfepirv2sg1prdstr03.blob.core.windows.net:80/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml] [None] [None]
2017/07/12 06:30:09.572601 VERBOSE Fetch failed from [https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml]: [000009] HTTP GET failed
2017/07/12 06:30:09.591745 VERBOSE Manifest could not be downloaded, falling back to host plugin
2017/07/12 06:30:09.602838 VERBOSE HostGAPlugin: Getting API versions at [http://100.107.240.13:32526/versions]
2017/07/12 06:30:09.614843 VERBOSE HTTP connection [GET] [/versions] [None] [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d'}]
2017/07/12 06:30:09.632135 VERBOSE HTTP response status: [200]
2017/07/12 06:30:09.639179 INFO Event: name=WALinuxAgent, op=InitializeHostPlugin, message=
2017/07/12 06:30:09.650182 VERBOSE Fetch [http://100.107.240.13:32526/extensionArtifact] with headers [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d', 'x-ms-version': '2015-09-01', 'x-ms-host-config-name': u'77bbebc9f3994cc48fbef61834a1822e.0.77bbebc9f3994cc48fbef61834a1822e.0.wala692214ui4.1.xml', 'x-ms-artifact-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml'}]
2017/07/12 06:30:09.689246 VERBOSE HTTP connection [GET] [/extensionArtifact] [None] [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d', 'x-ms-version': '2015-09-01', 'x-ms-host-config-name': u'77bbebc9f3994cc48fbef61834a1822e.0.77bbebc9f3994cc48fbef61834a1822e.0.wala692214ui4.1.xml', 'x-ms-artifact-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml'}]
2017/07/12 06:30:09.763930 VERBOSE HTTP response status: [200]
2017/07/12 06:30:09.770335 VERBOSE Manifest downloaded successfully from host plugin
2017/07/12 06:30:09.778017 INFO Setting host plugin as default channel
2017/07/12 06:30:09.785914 VERBOSE Load ExtensionManifest.xml
2017/07/12 06:30:09.794175 VERBOSE Loading Agent WALinuxAgent-2.2.10 from package package
2017/07/12 06:30:09.803674 VERBOSE Agent WALinuxAgent-2.2.10 error state: Last Failure: 0.0, Total Failures: 0, Fatal: False
2017/07/12 06:30:09.816401 VERBOSE Ensuring Agent WALinuxAgent-2.2.10 is downloaded
2017/07/12 06:30:09.825242 VERBOSE Using host plugin as default channel
2017/07/12 06:30:09.833194 VERBOSE HTTP proxy: [172.16.0.1:3128]
2017/07/12 06:30:09.839940 VERBOSE HTTP connection [GET] [http://100.107.240.13:32526/extensionArtifact] [None] [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d', 'x-ms-artifact-manifest-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml', 'x-ms-version': '2015-09-01', 'x-ms-host-config-name': u'77bbebc9f3994cc48fbef61834a1822e.0.77bbebc9f3994cc48fbef61834a1822e.0.wala692214ui4.1.xml', 'x-ms-artifact-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.10'}]
2017/07/12 06:30:19.911177 VERBOSE HTTP connection [GET] [http://100.107.240.13:32526/extensionArtifact] [None] [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d', 'x-ms-artifact-manifest-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml', 'x-ms-version': '2015-09-01', 'x-ms-host-config-name': u'77bbebc9f3994cc48fbef61834a1822e.0.77bbebc9f3994cc48fbef61834a1822e.0.wala692214ui4.1.xml', 'x-ms-artifact-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.10'}]
2017/07/12 06:30:29.992187 VERBOSE HTTP connection [GET] [http://100.107.240.13:32526/extensionArtifact] [None] [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d', 'x-ms-artifact-manifest-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml', 'x-ms-version': '2015-09-01', 'x-ms-host-config-name': u'77bbebc9f3994cc48fbef61834a1822e.0.77bbebc9f3994cc48fbef61834a1822e.0.wala692214ui4.1.xml', 'x-ms-artifact-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.10'}]
2017/07/12 06:30:39.543400 VERBOSE Found event file: /var/lib/waagent/events/1499855409649965.tld
2017/07/12 06:30:39.554873 VERBOSE Processed event file: /var/lib/waagent/events/1499855409649965.tld
2017/07/12 06:30:39.566265 VERBOSE HTTP connection [POST] [/machine?comp=telemetrydata] [<?xml version="1.0"?><TelemetryData version="1.0"><Provider id="69B669B9-4AF8-4C50-BDC4-6006FA76E975"><Event id="1"><![CDATA[<Param Name="Name" Value="WALinuxAgent" T="mt:wstr" /><Param Name="Version" Value="2.2.14" T="mt:wstr" /><Param Name="IsInternal" Value="False" T="mt:bool" /><Param Name="Operation" Value="InitializeHostPlugin" T="mt:wstr" /><Param Name="OperationSuccess" Value="True" T="mt:bool" /><Param Name="Message" Value="" T="mt:wstr" /><Param Name="Duration" Value="0" T="mt:uint64" /><Param Name="ExtensionType" Value="" T="mt:wstr" /><Param Name="OSVersion" Value="Linux:redhat-6.9-Santiago:2.6.32-696.3.2.el6.x86_64" T="mt:wstr" /><Param Name="GAVersion" Value="WALinuxAgent-2.2.14" T="mt:wstr" /><Param Name="RAM" Value="1679" T="mt:uint64" /><Param Name="Processors" Value="1" T="mt:uint64" /><Param Name="VMName" Value="wala692214ui4" T="mt:wstr" /><Param Name="TenantName" Value="77bbebc9f3994cc48fbef61834a1822e" T="mt:wstr" /><Param Name="RoleName" Value="wala692214ui4" T="mt:wstr" /><Param Name="RoleInstanceName" Value="77bbebc9f3994cc48fbef61834a1822e.wala692214ui4" T="mt:wstr" /><Param Name="ContainerId" Value="d4384bb2-4f5c-4680-8c3d-9fa51841ba7d" T="mt:wstr" />]]></Event></Provider></TelemetryData>] [{'Content-Type': 'text/xml;charset=utf-8', 'x-ms-version': '2012-11-30', 'x-ms-agent-name': 'WALinuxAgent'}]
2017/07/12 06:30:39.768153 VERBOSE HTTP response status: [200]
2017/07/12 06:30:40.064471 VERBOSE Agent WALinuxAgent-2.2.10 download from http://100.107.240.13:32526/extensionArtifact failed [[000009] HTTP GET failed]
2017/07/12 06:30:40.079068 WARNING Host plugin download unsuccessful
2017/07/12 06:30:40.089613 VERBOSE Using host plugin as default channel
2017/07/12 06:30:40.097071 VERBOSE HTTP proxy: [172.16.0.1:3128]
2017/07/12 06:30:40.103549 VERBOSE HTTP connection [GET] [http://100.107.240.13:32526/extensionArtifact] [None] [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d', 'x-ms-artifact-manifest-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml', 'x-ms-version': '2015-09-01', 'x-ms-host-config-name': u'77bbebc9f3994cc48fbef61834a1822e.0.77bbebc9f3994cc48fbef61834a1822e.0.wala692214ui4.1.xml', 'x-ms-artifact-location': u'https://rdfepirv2sg1prdstr04.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.10'}]
2017/07/12 06:30:50.176833 VERBOSE HTTP connection [GET] [http://100.107.240.13:32526/extensionArtifact] [None] [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d', 'x-ms-artifact-manifest-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml', 'x-ms-version': '2015-09-01', 'x-ms-host-config-name': u'77bbebc9f3994cc48fbef61834a1822e.0.77bbebc9f3994cc48fbef61834a1822e.0.wala692214ui4.1.xml', 'x-ms-artifact-location': u'https://rdfepirv2sg1prdstr04.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.10'}]
2017/07/12 06:31:00.249870 VERBOSE HTTP connection [GET] [http://100.107.240.13:32526/extensionArtifact] [None] [{'x-ms-containerid': u'd4384bb2-4f5c-4680-8c3d-9fa51841ba7d', 'x-ms-artifact-manifest-location': u'https://rdfepirv2sg1prdstr03.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent_Prod_asiasoutheast_manifest.xml', 'x-ms-version': '2015-09-01', 'x-ms-host-config-name': u'77bbebc9f3994cc48fbef61834a1822e.0.77bbebc9f3994cc48fbef61834a1822e.0.wala692214ui4.1.xml', 'x-ms-artifact-location': u'https://rdfepirv2sg1prdstr04.blob.core.windows.net/7d89d439b79f4452950452399add2c90/Microsoft.OSTCLinuxAgent__Prod__2.2.10'}]
2017/07/12 06:31:10.331413 VERBOSE Agent WALinuxAgent-2.2.10 download from http://100.107.240.13:32526/extensionArtifact failed [[000009] HTTP GET failed]
2017/07/12 06:31:10.347366 WARNING Host plugin download unsuccessful
2017/07/12 06:31:10.355276 VERBOSE Using host plugin as default channel
2017/07/12 06:31:10.363528 VERBOSE HTTP proxy: [172.16.0.1:3128]
...
```

Discussion:

Patch:
diff --git a/azurelinuxagent/common/protocol/restapi.py b/azurelinuxagent/common/protocol/restapi.py
index 275cedb0..540ec5d9 100644
--- a/azurelinuxagent/common/protocol/restapi.py
+++ b/azurelinuxagent/common/protocol/restapi.py
@@ -321,9 +321,9 @@ class Protocol(DataContract):
     def get_artifacts_profile(self):
         raise NotImplementedError()
 
-    def download_ext_handler_pkg(self, uri, headers=None):
+    def download_ext_handler_pkg(self, uri, headers=None, use_proxy=True):
         try:
-            resp = restutil.http_get(uri, use_proxy=True, headers=headers)
+            resp = restutil.http_get(uri, headers=headers, use_proxy=use_proxy)
             if restutil.request_succeeded(resp):
                 return resp.read()
         except Exception as e:
diff --git a/azurelinuxagent/common/protocol/wire.py b/azurelinuxagent/common/protocol/wire.py
index a92e0b89..2dc5297c 100644
--- a/azurelinuxagent/common/protocol/wire.py
+++ b/azurelinuxagent/common/protocol/wire.py
@@ -172,7 +172,7 @@ class WireProtocol(Protocol):
             logger.warn("Download did not succeed, falling back to host plugin")
             host = self.client.get_host_plugin()
             uri, headers = host.get_artifact_request(uri, host.manifest_uri)
-            package = super(WireProtocol, self).download_ext_handler_pkg(uri, headers=headers)
+            package = super(WireProtocol, self).download_ext_handler_pkg(uri, headers=headers, use_proxy=False)
         return package
 
     def report_provision_status(self, provision_status):
diff --git a/azurelinuxagent/ga/env.py b/azurelinuxagent/ga/env.py
index 0456cb06..26487818 100644
--- a/azurelinuxagent/ga/env.py
+++ b/azurelinuxagent/ga/env.py
@@ -86,7 +86,7 @@ class EnvHandler(object):
                     version=CURRENT_VERSION,
                     op=WALAEventOperation.Firewall,
                     is_success=success,
-                    log_event=True)
+                    log_event=False)
 
             timeout = conf.get_root_device_scsi_timeout()
             if timeout is not None:
diff --git a/azurelinuxagent/ga/monitor.py b/azurelinuxagent/ga/monitor.py
index e3ef292f..9b90aa7b 100644
--- a/azurelinuxagent/ga/monitor.py
+++ b/azurelinuxagent/ga/monitor.py
@@ -203,7 +203,8 @@ class MonitorHandler(object):
                     version=CURRENT_VERSION,
                     op=WALAEventOperation.HeartBeat,
                     is_success=True,
-                    message=msg)
+                    message=msg,
+                    log_event=False)
 
                 counter += 1
 
@@ -222,7 +223,7 @@ class MonitorHandler(object):
                         version=CURRENT_VERSION,
                         op=WALAEventOperation.HttpErrors,
                         is_success=False,
-                        msg=msg)
+                        message=msg)
 
             try:
                 self.collect_and_send_events()
diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py
index 26009299..1b6f913e 100644
--- a/azurelinuxagent/ga/update.py
+++ b/azurelinuxagent/ga/update.py
@@ -295,7 +295,7 @@ class UpdateHandler(object):
                         duration=elapsed_milliseconds(utc_start),
                         message="Incarnation {0}".format(
                                             exthandlers_handler.last_etag),
-                        log_event=True)
+                        log_event=False)
 
                 time.sleep(GOAL_STATE_INTERVAL)
 
diff --git a/azurelinuxagent/pa/provision/cloudinit.py b/azurelinuxagent/pa/provision/cloudinit.py
index 22c3f9ca..fa47799a 100644
--- a/azurelinuxagent/pa/provision/cloudinit.py
+++ b/azurelinuxagent/pa/provision/cloudinit.py
@@ -64,7 +64,7 @@ class CloudInitProvisionHandler(ProvisionHandler):
             logger.info("Finished provisioning")
 
             self.report_ready(thumbprint)
-            self.report_event("Provision succeed",
+            self.report_event("Provisioning with cloud-init succeeded",
                 is_success=True,
                 duration=elapsed_milliseconds(utc_start))
             self.report_event(self.create_guest_state_telemetry_messsage(),
diff --git a/azurelinuxagent/pa/provision/default.py b/azurelinuxagent/pa/provision/default.py
index 5d6f1565..44e171b4 100644
--- a/azurelinuxagent/pa/provision/default.py
+++ b/azurelinuxagent/pa/provision/default.py
@@ -89,7 +89,7 @@ class ProvisionHandler(object):
 
             self.write_provisioned()
 
-            self.report_event("Provision succeeded",
+            self.report_event("Provisioning succeeded",
                 is_success=True,
                 duration=elapsed_milliseconds(utc_start))
 
diff --git a/azurelinuxagent/pa/provision/factory.py b/azurelinuxagent/pa/provision/factory.py
index d87765f3..9e88618f 100644
--- a/azurelinuxagent/pa/provision/factory.py
+++ b/azurelinuxagent/pa/provision/factory.py
@@ -16,9 +16,7 @@
 #
 
 import azurelinuxagent.common.conf as conf
-import azurelinuxagent.common.logger as logger
 
-from azurelinuxagent.common.utils.textutil import Version
 from azurelinuxagent.common.version import DISTRO_NAME, DISTRO_VERSION, \
                                      DISTRO_FULL_NAME
 


Test patch:
diff --git a/tests/pa/test_provision.py b/tests/pa/test_provision.py
index ab0a9102..2c2d2c9b 100644
--- a/tests/pa/test_provision.py
+++ b/tests/pa/test_provision.py
@@ -151,7 +151,7 @@ class TestProvision(AgentTestCase):
 
         ph.run()
 
-        call1 = call("Provision succeeded", duration=ANY, is_success=True)
+        call1 = call("Provisioning succeeded", duration=ANY, is_success=True)
         call2 = call(ANY, is_success=True, operation=WALAEventOperation.GuestState)
         ph.report_event.assert_has_calls([call1, call2])