Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

GET vmSettings Failed to generate proper error response #3256

Open
jespli opened this issue Nov 4, 2024 · 6 comments
Open

GET vmSettings Failed to generate proper error response #3256

jespli opened this issue Nov 4, 2024 · 6 comments
Assignees

Comments

@jespli
Copy link

jespli commented Nov 4, 2024

I'm using LinuxAgent-2.11.1.12 running on kylin 10 with Python: 3.7.9.
Agent is running with the following error. Appreciated for your help.

2024-10-31T01:35:36.647036Z INFO Daemon Daemon WireServer endpoint is not found. Rerun dhcp handler
2024-10-31T01:35:36.682818Z INFO Daemon Daemon Test for route to 168.63.129.16
2024-10-31T01:35:36.710750Z INFO Daemon Daemon Route to 168.63.129.16 exists
2024-10-31T01:35:36.737377Z INFO Daemon Daemon Wire server endpoint:168.63.129.16
2024-10-31T01:35:36.770986Z INFO Daemon Daemon Fabric preferred wire protocol version:2015-04-05
2024-10-31T01:35:36.804250Z INFO Daemon Daemon Wire protocol version:2012-11-30
2024-10-31T01:35:36.832433Z INFO Daemon Daemon Server preferred version:2015-04-05
2024-10-31T01:35:36.876949Z INFO Daemon Daemon Initializing goal state during protocol detection
2024-10-31T01:35:36.910990Z INFO Daemon Daemon Forcing an update of the goal state.
2024-10-31T01:35:36.947560Z INFO Daemon Fetched a new incarnation for the WireServer goal state [incarnation 1]
2024-10-31T01:35:36.994446Z INFO Daemon Daemon WireServer is not responding. Reset dhcp endpoint
2024-10-31T01:35:37.027408Z INFO Daemon Daemon Protocol endpoint not found: [ProtocolError] GET vmSettings [correlation ID: a5d3ad6c-1393-4013-89fc-893801463715 eTag: None]: [HTTP Failed] [500: Internal Server Error] b'Server error. Failed to generate proper error response.'
2024-10-31T01:35:37.116962Z INFO Daemon Daemon Retry detect protocol: retry=1

@maddieford maddieford self-assigned this Nov 26, 2024
@maddieford
Copy link
Contributor

@jespli could you please provide full agent log at /var/log/waagent.log, or at least logs 5 minutes before and after the issue. Thank you

@jespli
Copy link
Author

jespli commented Nov 27, 2024

I tried to troubleshoot with python and found the point for failure, seems like the wireserver does not have the VM setting info?

protocol.detect(init_goal_state="true", save_to_history="false")
Traceback (most recent call last):
File "", line 1, in
File "/usr/local/lib/python3.7/site-packages/azurelinuxagent/common/protocol/wire.py", line 89, in detect
self.client.reset_goal_state(save_to_history=save_to_history)
File "/usr/local/lib/python3.7/site-packages/azurelinuxagent/common/protocol/wire.py", line 803, in reset_goal_state
self._goal_state = GoalState(self, goal_state_properties=goal_state_properties, silent=silent, save_to_history=save_to_history)
File "/usr/local/lib/python3.7/site-packages/azurelinuxagent/common/protocol/goal_state.py", line 104, in init
self.update(silent=silent)
File "/usr/local/lib/python3.7/site-packages/azurelinuxagent/common/protocol/goal_state.py", line 211, in update
self._update(force_update=False)
File "/usr/local/lib/python3.7/site-packages/azurelinuxagent/common/protocol/goal_state.py", line 244, in _update
vm_settings, vm_settings_updated = GoalState._fetch_vm_settings(self._wire_client, force_update=force_update)
File "/usr/local/lib/python3.7/site-packages/azurelinuxagent/common/protocol/goal_state.py", line 424, in _fetch_vm_settings
vm_settings, vm_settings_updated = wire_client.get_host_plugin().fetch_vm_settings(force_update=force_update)
File "/usr/local/lib/python3.7/site-packages/azurelinuxagent/common/protocol/hostplugin.py", line 533, in fetch_vm_settings
raise ProtocolError(error_description)
azurelinuxagent.common.exception.ProtocolError: [ProtocolError] GET vmSettings [correlation ID: 16508e3c-f756-413f-b62b-2af57dc39daa eTag: None]: [HTTP Failed] [500: Internal Server Error] b'Server error. Failed to generate proper error response.'

======================================
Details for waagent.log
2024-11-27T00:32:28.641928Z INFO Daemon Daemon WireServer endpoint is not found. Rerun dhcp handler
2024-11-27T00:32:28.673158Z INFO Daemon Daemon Test for route to 168.63.129.16
2024-11-27T00:32:28.696856Z INFO Daemon Daemon Route to 168.63.129.16 exists
2024-11-27T00:32:28.721918Z INFO Daemon Daemon Wire server endpoint:168.63.129.16
2024-11-27T00:32:28.747329Z VERBOSE Daemon Daemon HTTP connection [GET] [/?comp=versions] [None] [{'Connection': 'close', 'User-Agent': 'WALinuxAgent/2.11.1.12'}]
2024-11-27T00:32:28.795861Z VERBOSE Daemon Daemon [HTTP Response] Status Code 200
2024-11-27T00:32:28.822277Z VERBOSE Daemon Daemon Load Version.xml
2024-11-27T00:32:28.843853Z INFO Daemon Daemon Fabric preferred wire protocol version:2015-04-05
2024-11-27T00:32:28.872578Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2015-04-05
2024-11-27T00:32:28.904525Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2012-11-30
2024-11-27T00:32:28.935956Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2012-09-15
2024-11-27T00:32:28.966710Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2012-05-15
2024-11-27T00:32:29.000453Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2011-12-31
2024-11-27T00:32:29.034397Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2011-10-15
2024-11-27T00:32:29.069202Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2011-08-31
2024-11-27T00:32:29.103294Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2011-04-07
2024-11-27T00:32:29.137258Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2010-12-15
2024-11-27T00:32:29.173555Z VERBOSE Daemon Daemon Fabric supported wire protocol version:2010-28-10
2024-11-27T00:32:29.207528Z INFO Daemon Daemon Wire protocol version:2012-11-30
2024-11-27T00:32:29.235028Z INFO Daemon Daemon Server preferred version:2015-04-05
2024-11-27T00:32:29.286712Z INFO Daemon Daemon Initializing goal state during protocol detection
2024-11-27T00:32:29.319122Z INFO Daemon Daemon Forcing an update of the goal state.
2024-11-27T00:32:29.348506Z VERBOSE Daemon Daemon HTTP connection [GET] [/machine/?comp=goalstate] [None] [{'x-ms-agent-name': 'WALinuxAgent', 'x-ms-version': '2012-11-30', 'Connection': 'close', 'User-Agent': 'WALinuxAgent/2.11.1.12'}]
2024-11-27T00:32:29.429213Z VERBOSE Daemon Daemon [HTTP Response] Status Code 200
2024-11-27T00:32:29.458053Z INFO Daemon Fetched a new incarnation for the WireServer goal state [incarnation 2]
2024-11-27T00:32:29.492904Z VERBOSE Daemon Daemon HTTP connection [GET] [/machine/?comp=goalstate] [None] [{'x-ms-agent-name': 'WALinuxAgent', 'x-ms-version': '2012-11-30', 'Connection': 'close', 'User-Agent': 'WALinuxAgent/2.11.1.12'}]
2024-11-27T00:32:29.570137Z VERBOSE Daemon Daemon [HTTP Response] Status Code 200
2024-11-27T00:32:29.597544Z VERBOSE Daemon Daemon HTTP connection [GET] [/vmSettings] [None] [{'x-ms-version': '2015-09-01', 'x-ms-containerid': '4554a579-e735-407d-9503-a397c93735ae', 'x-ms-host-config-name': '4554a579-e735-407d-9503-a397c93735ae.2.4554a579-e735-407d-9503-a397c93735ae.2._as2trjhnetvm03.2.xml', 'x-ms-client-correlationid': '1fd280c8-37d9-4c74-b835-f3f27838b051', 'Connection': 'close', 'User-Agent': 'WALinuxAgent/2.11.1.12'}]
2024-11-27T00:32:29.728123Z VERBOSE Daemon Daemon [HTTP Response] Status Code 500
2024-11-27T00:32:29.755864Z INFO Daemon Daemon WireServer is not responding. Reset dhcp endpoint
2024-11-27T00:32:29.786345Z INFO Daemon Daemon Protocol endpoint not found: [ProtocolError] GET vmSettings [correlation ID: 1fd280c8-37d9-4c74-b835-f3f27838b051 eTag: None]: [HTTP Failed] [500: Internal Server Error] b'Server error. Failed to generate proper error response.'

@maddieford
Copy link
Contributor

@jespli Do you have full agent log and able to share it?

@jespli
Copy link
Author

jespli commented Nov 27, 2024

waagent.log

@maddieford
Copy link
Contributor

Thanks for sharing the logs @jespli
The agent fetches the vm settings via HostGA Plugin during protocol detection and is getting a 500 internal server error response, which is causing the agent to enter a loop trying to detect protocol.

I've reached out to the HostGA Plugin team to investigate the 500 response. I will update this issue with their investigation

@maddieford
Copy link
Contributor

@jespli Could you please provide the VM name, resource group name, and subscription Id? Those details will be needed for the HostGA investigation

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants