You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
Encountering errors in the log when executing commands in virtual machine instance. Python script, env info, and sample logs is included in the end.
A virtual machine instance is created and started with wait=True.
Executing commands with execute will return with return code -1.
File operations will still fail with LXD VM agent isn't currently running.
This part seems to be related to LXD VM agent. Is there a way to ensure it is running after instance is started with wait=True?
After the LXD VM agent seems to be running as file operation no longer fails, logs such as the follow can still be observed when executing commands:
DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/543f05e1-8b56-4c02-b6f8-7427802ae727 HTTP/1.1" 200 939INFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/543f05e1-8b56-4c02-b6f8-7427802ae727 HTTP/1.1" 200 950INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'
❯ python pylxd_test.pyINFO:__main__:Starting up...DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0 HTTP/1.1" 200 NoneDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances HTTP/1.1" 202 514DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/ba4a7039-a1d8-4c7c-a93a-612442e3bb88 HTTP/1.1" 200 451DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/ba4a7039-a1d8-4c7c-a93a-612442e3bb88/wait HTTP/1.1" 200 613DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/ba4a7039-a1d8-4c7c-a93a-612442e3bb88 HTTP/1.1" 200 613DEBUG:urllib3.connectionpool:http://localhost:None "PUT /1.0/instances/test/state HTTP/1.1" 202 514DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/08c0ee13-0fa3-410d-a4e5-9830a098c21b HTTP/1.1" 200 451DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/08c0ee13-0fa3-410d-a4e5-9830a098c21b/wait HTTP/1.1" 200 451DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/08c0ee13-0fa3-410d-a4e5-9830a098c21b HTTP/1.1" 200 451DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test HTTP/1.1" 200 1916DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test HTTP/1.1" 200 1916INFO:__main__:Instance startedINFO:__main__:Testing some operations...DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']ERROR:ws4py:Terminating websocket [Bound to ''] due to exception: BrokenPipeError(32, 'Broken pipe') in once methodINFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Terminating websocket [Bound to ''] due to exception: BrokenPipeError(32, 'Broken pipe') in once methodINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/3d738cbf-b9a5-482b-be42-f27d7dccdc24 HTTP/1.1" 200 987INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [-1, , ]DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 500 141ERROR:__main__:Errors encountered.Traceback (most recent call last): File "/home/user/work/tmp/pylxd_test.py", line 72, in main write_random_data_file(instance, TEST_FILE, FILE_SIZE) File "/home/user/work/tmp/pylxd_test.py", line 40, in write_random_data_file instance.files.put(filename, data) File "/home/user/work/tmp/venv/lib/python3.10/site-packages/pylxd/models/instance.py", line 114, in put response = self._endpoint.post( File "/home/user/work/tmp/venv/lib/python3.10/site-packages/pylxd/client.py", line 216, in post self._assert_response(response, allowed_status_codes=(200, 201, 202)) File "/home/user/work/tmp/venv/lib/python3.10/site-packages/pylxd/client.py", line 145, in _assert_response raise exceptions.LXDAPIException(response)pylxd.exceptions.LXDAPIException: LXD VM agent isn't currently runningDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']ERROR:ws4py:Terminating websocket [Bound to ''] due to exception: BrokenPipeError(32, 'Broken pipe') in once methodINFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Terminating websocket [Bound to ''] due to exception: BrokenPipeError(32, 'Broken pipe') in once methodINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/37f202ec-c1cc-471e-b819-a16532df6766 HTTP/1.1" 200 987INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [-1, , ]DEBUG:urllib3.connectionpool:Resetting dropped connection: localhostDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 500 141ERROR:__main__:Errors encountered.Traceback (most recent call last): File "/home/user/work/tmp/pylxd_test.py", line 72, in main write_random_data_file(instance, TEST_FILE, FILE_SIZE) File "/home/user/work/tmp/pylxd_test.py", line 40, in write_random_data_file instance.files.put(filename, data) File "/home/user/work/tmp/venv/lib/python3.10/site-packages/pylxd/models/instance.py", line 114, in put response = self._endpoint.post( File "/home/user/work/tmp/venv/lib/python3.10/site-packages/pylxd/client.py", line 216, in post self._assert_response(response, allowed_status_codes=(200, 201, 202)) File "/home/user/work/tmp/venv/lib/python3.10/site-packages/pylxd/client.py", line 145, in _assert_response raise exceptions.LXDAPIException(response)pylxd.exceptions.LXDAPIException: LXD VM agent isn't currently runningDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1000INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/31869010-d3f6-4f57-94b0-ae625cfaad0b HTTP/1.1" 200 937INFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/31869010-d3f6-4f57-94b0-ae625cfaad0b HTTP/1.1" 200 949INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [0, hello, ]DEBUG:urllib3.connectionpool:Resetting dropped connection: localhostDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 108INFO:__main__:Written random data to /home/ubuntu/test_file.binDEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 10000000INFO:__main__:Read 10 bytes of data from /home/ubuntu/test_file.bin: d199e204821c5ed196bcDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/29270d47-211f-49e9-a928-1aa615296ab1 HTTP/1.1" 200 939INFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/29270d47-211f-49e9-a928-1aa615296ab1 HTTP/1.1" 200 950INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [0, hello, ]DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 108INFO:__main__:Written random data to /home/ubuntu/test_file.binDEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 10000000INFO:__main__:Read 10 bytes of data from /home/ubuntu/test_file.bin: bb1e44c925f72685979fDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/4f2e9e21-41aa-4702-942d-03c860b13723 HTTP/1.1" 200 939INFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/4f2e9e21-41aa-4702-942d-03c860b13723 HTTP/1.1" 200 950INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [0, hello, ]DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 108INFO:__main__:Written random data to /home/ubuntu/test_file.binDEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 10000000INFO:__main__:Read 10 bytes of data from /home/ubuntu/test_file.bin: a7d404771490d02c82cbDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/104ba683-6bfa-44a1-8442-197fa96776aa HTTP/1.1" 200 939ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']INFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/104ba683-6bfa-44a1-8442-197fa96776aa HTTP/1.1" 200 950INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [0, hello, ]DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 108INFO:__main__:Written random data to /home/ubuntu/test_file.binDEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 10000000INFO:__main__:Read 10 bytes of data from /home/ubuntu/test_file.bin: 8f2c42f4cf2c75ff620fDEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/da8e1579-80bf-4042-9f4e-1fab6a743f45 HTTP/1.1" 200 939INFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/da8e1579-80bf-4042-9f4e-1fab6a743f45 HTTP/1.1" 200 950INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [0, hello, ]DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 108INFO:__main__:Written random data to /home/ubuntu/test_file.binDEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 10000000INFO:__main__:Read 10 bytes of data from /home/ubuntu/test_file.bin: 06a126f754e76114d997DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/06a10cf3-996c-4d40-a580-41c7a4352526 HTTP/1.1" 200 939INFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/06a10cf3-996c-4d40-a580-41c7a4352526 HTTP/1.1" 200 950INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [0, hello, ]DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 108INFO:__main__:Written random data to /home/ubuntu/test_file.binDEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 10000000INFO:__main__:Read 10 bytes of data from /home/ubuntu/test_file.bin: 1e24c1ac08f0afb6b3b2DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/247745dc-d303-4367-884f-7f2cdbc874ae HTTP/1.1" 200 939INFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/247745dc-d303-4367-884f-7f2cdbc874ae HTTP/1.1" 200 950INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [0, hello, ]DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 108INFO:__main__:Written random data to /home/ubuntu/test_file.binDEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 10000000INFO:__main__:Read 10 bytes of data from /home/ubuntu/test_file.bin: 96ad3b63dbbe41e86bc2DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/exec HTTP/1.1" 202 1002INFO:ws4py:Using epollINFO:ws4py:Managing websocket [Bound to '']INFO:ws4py:Managing websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/543f05e1-8b56-4c02-b6f8-7427802ae727 HTTP/1.1" 200 939INFO:ws4py:Terminating websocket [Bound to '']ERROR:ws4py:Failed to receive dataTraceback (most recent call last): File "/home/user/work/tmp/venv/lib/python3.10/site-packages/ws4py/websocket.py", line 394, in once b = self.sock.recv(self.reading_buffer_size)ConnectionResetError: [Errno 104] Connection reset by peerINFO:ws4py:Terminating websocket [Bound to '']DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/543f05e1-8b56-4c02-b6f8-7427802ae727 HTTP/1.1" 200 950INFO:ws4py:Closing all websockets with [1001] 'Server is shutting down'INFO:__main__:Echoing hello: [0, hello, ]DEBUG:urllib3.connectionpool:http://localhost:None "POST /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 108INFO:__main__:Written random data to /home/ubuntu/test_file.binDEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/instances/test/files?path=%2Fhome%2Fubuntu%2Ftest_file.bin HTTP/1.1" 200 10000000INFO:__main__:Read 10 bytes of data from /home/ubuntu/test_file.bin: a98f105fe3de7e2e0991DEBUG:urllib3.connectionpool:http://localhost:None "PUT /1.0/instances/test/state HTTP/1.1" 202 514DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/9bece8d3-1496-48c0-9b27-9110316f70e6 HTTP/1.1" 200 451DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/9bece8d3-1496-48c0-9b27-9110316f70e6/wait HTTP/1.1" 200 451DEBUG:urllib3.connectionpool:http://localhost:None "GET /1.0/operations/9bece8d3-1496-48c0-9b27-9110316f70e6 HTTP/1.1" 200 451INFO:__main__:Cleanup completed.
The text was updated successfully, but these errors were encountered:
I can't really comment on pylxd/ws4py, but for the LXD agent, you need to setup some kind of loop to see when the VM is connected. LXD itself doesn't know when the agent is ready as that would require frequent polling of all the VMs. Instead it just tries to interact with the agent as needed.
In shell, you'd probably want to do something like:
lxc list -cN -fcsv NAME
If you get -1, no agent is responding, if you get a value higher than 0, then you're talking to an agent.
An alternative is a busy loop of lxc exec NAME /bin/true 2>/dev/null
@yhaliaw, are you using pylxd package available from pip? In my case #376 all errors were caused by an ols bug with pip version of the package. Try to use latest package from GitHub repo and check if this solves your issue.
P.S. Here's the command to install latest pylxd package
Encountering errors in the log when executing commands in virtual machine instance. Python script, env info, and sample logs is included in the end.
A virtual machine instance is created and started with
wait=True
.Executing commands with
execute
will return with return code-1
.File operations will still fail with
LXD VM agent isn't currently running
.This part seems to be related to LXD VM agent. Is there a way to ensure it is running after instance is started with
wait=True
?After the LXD VM agent seems to be running as file operation no longer fails, logs such as the follow can still be observed when executing commands:
environment:
ubuntu-22.04
package versions:
Script:
Sample log:
The text was updated successfully, but these errors were encountered: