[Elastic Agent] Agent fails to start when installed through proxy

[lthach2]

Attempting to install Elastic Agent via a proxy results in the agent service being installed, but it fails to start. This results in the host populating in the Fleet web UI but stuck on "Updating." When installing without a proxy, the agent service starts successfully and the host shows as "Healthy" in the Fleet web UI.

• Elastic Version: 7.14.0-SNAPSHOT
• Agent Version:
  Binary: 7.14.0 (build: 331b419 at 2021-07-22 02:24:06 +0000 UTC)
  Daemon: 7.14.0 (build: 331b419 at 2021-07-22 02:24:06 +0000 UTC)
• Operating System: Windows 10
• Steps to Reproduce:

1. Setup a proxy server if one is not available (I setup a simple Squid proxy)

2. Install the agent using the proxy-url flag and specify the proxy URL
   

3. Agent should successfully enroll and appear in the Fleet UI but show as "Updating"
   
   

4. Check whether Elastic Agent service is running. It will show as Stopped.
   

5. Attempting to manually start the agent results in this error:
   PS C:\Program Files\Elastic\Agent> .\elastic-agent.exe restart Error: Failed trigger restart of daemon: rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing open \\\\.\\pipe\\elastic-agent-system: The system cannot find the file specified."
   

The elastic-agent-json.log located in C:\Program Files\Elastic\Agent\data\elastic-agent-331b41\logs shows:

{"log.level":"info","@timestamp":"2021-07-28T14:18:52.631Z","log.origin":{"file.name":"application/application.go","file.line":66},"message":"Detecting execution mode","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:52.632Z","log.origin":{"file.name":"application/application.go","file.line":75},"message":"Agent is managed locally","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:52.633Z","log.origin":{"file.name":"capabilities/capabilities.go","file.line":59},"message":"capabilities file not found in C:\\Program Files\\Elastic\\Agent\\capabilities.yml","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:53.116Z","log.logger":"composable.providers.docker","log.origin":{"file.name":"docker/docker.go","file.line":43},"message":"Docker provider skipped, unable to connect: protocol not available","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:53.117Z","log.logger":"api","log.origin":{"file.name":"api/server.go","file.line":62},"message":"Starting stats endpoint","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:53.117Z","log.origin":{"file.name":"application/local_mode.go","file.line":168},"message":"Agent is starting","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:53.117Z","log.logger":"api","log.origin":{"file.name":"api/server.go","file.line":64},"message":"Metrics endpoint listening on: \\\\.\\pipe\\elastic-agent (configured: npipe:///elastic-agent)","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:53.123Z","log.origin":{"file.name":"application/local_mode.go","file.line":178},"message":"Agent is stopped","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:53.124Z","log.origin":{"file.name":"application/periodic.go","file.line":77},"message":"Configuration changes detected","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:53.133Z","log.origin":{"file.name":"stateresolver/stateresolver.go","file.line":48},"message":"New State ID is hHGK2Zze","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:53.133Z","log.origin":{"file.name":"stateresolver/stateresolver.go","file.line":49},"message":"Converging state requires execution of 2 step(s)","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:54.274Z","log.origin":{"file.name":"operation/operator.go","file.line":191},"message":"waiting for installer of pipeline 'default' to finish","ecs.version":"1.6.0"}
{"log.level":"error","@timestamp":"2021-07-28T14:18:56.778Z","log.origin":{"file.name":"status/reporter.go","file.line":236},"message":"Elastic Agent status changed to: 'error'","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:56.778Z","log.origin":{"file.name":"process/app.go","file.line":181},"message":"Signaling application to stop because of shutdown: metricbeat--7.14.0","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:56.781Z","log.origin":{"file.name":"stateresolver/stateresolver.go","file.line":48},"message":"New State ID is hHGK2Zze","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:56.781Z","log.origin":{"file.name":"stateresolver/stateresolver.go","file.line":49},"message":"Converging state requires execution of 2 step(s)","ecs.version":"1.6.0"}
{"log.level":"error","@timestamp":"2021-07-28T14:18:56.782Z","log.origin":{"file.name":"emitter/controller.go","file.line":120},"message":"Failed to render configuration with latest context from composable controller: operator: failed to execute step sc-run, error: context canceled: context canceled","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:56.851Z","log.logger":"reexec","log.origin":{"file.name":"reexec/reexec_windows.go","file.line":35},"message":"Running as Windows service Elastic Agent; triggering service restart","ecs.version":"1.6.0"}
{"log.level":"info","@timestamp":"2021-07-28T14:18:56.858Z","log.logger":"api","log.origin":{"file.name":"api/server.go","file.line":66},"message":"Stats endpoint (\\\\.\\pipe\\elastic-agent) finished: use of closed network connection","ecs.version":"1.6.0"}

[elasticmachine]

Pinging @elastic/agent (Team:Agent)

[EricDavisX]

@lthach2 I was going to ask, I believe you had cited a case where it WAS working, can you post the details and differences between the 2 scenarios here please?

[lthach2]

@EricDavisX Turns out I spoke too soon when initially reporting it was working. I assumed that since the install showed the agent was successfully enrolled, that everything was functioning, but turns out the agent service fails to start.

[lthach2]

Details about my test environment as it may require more testing in a fully on-prem environment:

• Stack is cloud hosted so Fleet server is cloud hosted as well
• Proxy is hosted in Endgame VMware lab with Internet access
• Endpoint is also hosted in Endgame VMware lab

[EricDavisX]

@urso @andresrc @ruflin any thoughts on first triage of this?

[lthach2]

Quick update after some additional testing on my end. I did another test in an on-prem environment and encountering the same issue with agent failing to start.

On-prem environment:

• ES: 7.14.0
• Agent: 7.14.0 (build: 331b419 at 2021-07-22 02:24:06 +0000 UTC)
• Fleet server installed on separate endpoint
• Proxy, fleet server, and endpoint are on the same network but I also tested with the endpoint on a different network

[urso]

In the logs you shared I don't see any error, only that Agent has been stopped. Can you archive and share the complete Agent folder?

It looks like enrollment did succeed. Agent write a fleet.yml file with fleet server connection details. We might want to check if that is correct.

[lthach2]

Hi @urso, sure thing. Below is the download link for the Agent folder from my test box.

https://upload.elastic.co/d/b70c1816893b40f1ed19dc6a300e0ec7b6956f6cfb948872eeb617787a39ef2f
Token: 909fcc333f10e707

[urso]

The authorization token seems to be wrong. I can't download your files.

[EricDavisX]

It worked for me yesterday - I've posted them to a shared google drive you, I'll slack you details.

[urso]

I think I found the bug. After enrolling the Agent creates/serializes its configuration to fleet.yml. Agent expects proxy_url to be a string, but unfortunately the type url.URL gets serialized into an object:

  proxy_url:
    scheme: http
    opaque: ""
    user: null
    host: 10.1.4.118:3128
    path: ""
    rawpath: ""
    forcequery: false
    rawquery: ""
    fragment: ""
    rawfragment: ""

With this serialization bug, proxy support is currently broken. I created an issue: #27187

[EricDavisX]

The fix was backported to 7.14.1 yesterday so we can wait a day to be sure the build has picked it up and we can re-test. Thanks @lthach2 . If we have questions about the next 'depth' we can test here, please do raise it to the team.

[lthach2]

Tested with the 7.14.1 agent and I'm now able to successfully install via proxy.

Looking at other parts of the test, where or how do we configure the Agent to connect to artifacts.elastic.co and Package Registry

[EricDavisX]

@lthach2 thanks so much. I pinged the team via slack, and we can follow up more in the test issue, if this doesn't get more comment in the next day. In that case we can just close it, as the one known issue is fixed - and we'll continue testing, and log separate issues as we find them

[ruflin]

Going to close this issue as the initial proxy problem seems to be resolved in the upcoming 7.14.1.