search

juju / python-libjuju

Python library for the Juju API
Apache License 2.0
60 stars 100 forks source link

[Bug]: Python 3.11 Started actions stay in Pending State forever #861

Closed addyess closed 1 year ago

addyess commented 1 year ago

Description

Using these library versions 

juju==3.1.2.0
websockets==11.0.3

and controller

my-model  addyess-aws  aws/us-east-2  3.1.2    unsupported  16:46:42-05:00

I start an action, but never get a result

Looking at the websocket debug:

connection 139765839393808 -> {
  "type": "Action",
  "request": "Run",
  "version": 7,
  "params": {
    "applications": [],
    "commands": "lspci -nnk",
    "execution-group": null,
    "machines": [],
    "parallel": null,
    "timeout": null,
    "units": [
      "kubernetes-worker/1"
    ],
    "workload-context": null
  },
  "request-id": 8
}
> TEXT '{\n  "type": "Action",\n  "request": "Run",\n  ...,\n  "request-id": 8\n}' [321 bytes]
% sending keepalive ping
> PING 3f 3e d1 ca [binary, 4 bytes]
% sending keepalive ping
> PING 7b bf 5d 97 [binary, 4 bytes]
connection 139765839393808 -> {
  "type": "Pinger",
  "request": "Ping",
  "version": 1,
  "params": {},
  "request-id": 9
}
> TEXT '{\n  "type": "Pinger",\n  "request": "Ping",\n ...,\n  "request-id": 9\n}' [94 bytes]
connection 139765838387216 -> {
  "type": "Pinger",
  "request": "Ping",
  "version": 1,
  "params": {},
  "request-id": 4
}
> TEXT '{\n  "type": "Pinger",\n  "request": "Ping",\n ...,\n  "request-id": 4\n}' [94 bytes]
< PONG 3f 3e d1 ca [binary, 4 bytes]
< TEXT '{"request-id":9,"response":{}}\n' [31 bytes]
% received keepalive pong
connection 139765839393808 <- {'request-id': 9, 'response': {}}
< PONG 7b bf 5d 97 [binary, 4 bytes]
% received keepalive pong
< TEXT '{"request-id":8,"response":{"operation":"operat...status":"pending"}]}}\n' [392 bytes]
< TEXT '{"request-id":6,"response":{"deltas":[["action"...01-01T00:00:00Z"}]]}}\n' [312 bytes]
connection 139765839393808 <- {'request-id': 8, 'response': {'operation': 'operation-267', 'actions': [{'action': {'tag': 'action-268', 'receiver': 'unit-kubernetes-worker-1', 'name': 'juju-exec', 'parameters': {'command': 'lspci -nnk', 'timeout': 0, 'workload-context': False}, 'parallel': True, 'execution-group': ''}, 'enqueued': '2023-05-26T21:44:17Z', 'started': '0001-01-01T00:00:00Z', 'completed': '0001-01-01T00:00:00Z', 'status': 'pending'}]}}
< TEXT '{"request-id":4,"response":{}}\n' [31 bytes]
connection 139765839393808 <- {'request-id': 6, 'response': {'deltas': [['action', 'change', {'model-uuid': '7d369704-bec7-406a-8d6c-d31942a94884', 'id': '268', 'receiver': 'kubernetes-worker/1', 'name': 'juju-exec', 'status': 'pending', 'message': '', 'enqueued': '2023-05-26T21:44:17Z', 'started': '0001-01-01T00:00:00Z', 'completed': '0001-01-01T00:00:00Z'}]]}}
Model changed: action add 268
connection 139765839393808 -> {
  "type": "AllWatcher",
  "request": "Next",
  "version": 3,
  "params": {},
  "Id": "1",
  "request-id": 10
}
> TEXT '{\n  "type": "AllWatcher",\n  "request": "Next"...\n  "request-id": 10\n}' [112 bytes]
connection 139765838387216 <- {'request-id': 4, 'response': {}}
connection 139765839393808 -> {
  "type": "Action",
  "request": "Actions",
  "version": 7,
  "params": {
    "entities": [
      {
        "tag": "action-268"
      }
    ]
  },
  "request-id": 11
}
> TEXT '{\n  "type": "Action",\n  "request": "Actions",...\n  "request-id": 11\n}' [169 bytes]
< TEXT '{"request-id":11,"response":{"results":[{"actio...status":"pending"}]}}\n' [365 bytes]
connection 139765839393808 <- {'request-id': 11, 'response': {'results': [{'action': {'tag': 'action-268', 'receiver': 'unit-kubernetes-worker-1', 'name': 'juju-exec', 'parameters': {'command': 'lspci -nnk', 'timeout': 0, 'workload-context': False}, 'parallel': True, 'execution-group': ''}, 'enqueued': '2023-05-26T21:44:17Z', 'started': '0001-01-01T00:00:00Z', 'completed': '0001-01-01T00:00:00Z', 'status': 'pending'}]}}
connection 139765839393808 -> {
  "type": "Action",
  "request": "Actions",
  "version": 7,
  "params": {
    "entities": [
      {
        "tag": "action-268"
      }
    ]
  },
  "request-id": 12
}
> TEXT '{\n  "type": "Action",\n  "request": "Actions",...\n  "request-id": 12\n}' [169 bytes]
< TEXT '{"request-id":12,"response":{"results":[{"actio...status":"pending"}]}}\n' [365 bytes]
connection 139765839393808 <- {'request-id': 12, 'response': {'results': [{'action': {'tag': 'action-268', 'receiver': 'unit-kubernetes-worker-1', 'name': 'juju-exec', 'parameters': {'command': 'lspci -nnk', 'timeout': 0, 'workload-context': False}, 'parallel': True, 'execution-group': ''}, 'enqueued': '2023-05-26T21:44:17Z', 'started': '0001-01-01T00:00:00Z', 'completed': '0001-01-01T00:00:00Z', 'status': 'pending'}]}}
connection 139765839393808 -> {
  "type": "Action",
  "request": "Actions",
  "version": 7,
  "params": {
    "entities": [
      {
        "tag": "action-268"
      }
    ]
  },
  "request-id": 13
}
> TEXT '{\n  "type": "Action",\n  "request": "Actions",...\n  "request-id": 13\n}' [169 bytes]
< TEXT '{"request-id":13,"response":{"results":[{"actio...status":"pending"}]}}\n' [365 bytes]
connection 139765839393808 <- {'request-id': 13, 'response': {'results': [{'action': {'tag': 'action-268', 'receiver': 'unit-kubernetes-worker-1', 'name': 'juju-exec', 'parameters': {'command': 'lspci -nnk', 'timeout': 0, 'workload-context': False}, 'parallel': True, 'execution-group': ''}, 'enqueued': '2023-05-26T21:44:17Z', 'started': '0001-01-01T00:00:00Z', 'completed': '0001-01-01T00:00:00Z', 'status': 'pending'}]}}
connection 139765839393808 -> {
  "type": "Action",
  "request": "Actions",
  "version": 7,
  "params": {
    "entities": [
      {
        "tag": "action-268"
      }
    ]
  },
  "request-id": 14
}
> TEXT '{\n  "type": "Action",\n  "request": "Actions",...\n  "request-id": 14\n}' [169 bytes]
< TEXT '{"request-id":14,"response":{"results":[{"actio...status":"pending"}]}}\n' [365 bytes]
connection 139765839393808 <- {'request-id': 14, 'response': {'results': [{'action': {'tag': 'action-268', 'receiver': 'unit-kubernetes-worker-1', 'name': 'juju-exec', 'parameters': {'command': 'lspci -nnk', 'timeout': 0, 'workload-context': False}, 'parallel': True, 'execution-group': ''}, 'enqueued': '2023-05-26T21:44:17Z', 'started': '0001-01-01T00:00:00Z', 'completed': '0001-01-01T00:00:00Z', 'status': 'pending'}]}}
connection 139765839393808 -> {
  "type": "Action",
  "request": "Actions",
  "version": 7,
  "params": {
    "entities": [
      {
        "tag": "action-268"
      }
    ]
  },
  "request-id": 15
}
> TEXT '{\n  "type": "Action",\n  "request": "Actions",...\n  "request-id": 15\n}' [169 bytes]
< TEXT '{"request-id":15,"response":{"results":[{"actio...status":"pending"}]}}\n' [365 bytes]
connection 139765839393808 <- {'request-id': 15, 'response': {'results': [{'action': {'tag': 'action-268', 'receiver': 'unit-kubernetes-worker-1', 'name': 'juju-exec', 'parameters': {'command': 'lspci -nnk', 'timeout': 0, 'workload-context': False}, 'parallel': True, 'execution-group': ''}, 'enqueued': '2023-05-26T21:44:17Z', 'started': '0001-01-01T00:00:00Z', 'completed': '0001-01-01T00:00:00Z', 'status': 'pending'}]}}

It seems the actions is there at the controller: using juju cli

❯ juju show-task 268                                                       
Task 268 pending

But these actions never complete

The same actions run fine when i use python3.10 and websockets==10.4

Urgency

Casually reporting

Python-libjuju version

3.1.2.0

Juju version

3.1.2

Reproduce / Test

unit = model.applications["kubernetes-worker/1"].unit
    action = await unit.run("lspci -nnk"")  # but honestly this could be anything
    action = await action.wait()
cderici commented 1 year ago

How's using a different python/websocket version affect the completion of a task on the unit? If that's actually the case (e.g. if I'm not misunderstanding this,) inspecting the difference on what's being sent out from pylibjuju (for each python/websocket version) should reveal the issue. I'll check it out as soon as I can @addyess , have a good Memorial Day weekend!

addyess commented 1 year ago

I can't seem to reproduce this anymore. I'm not sure what was I was experiencing.

cderici commented 1 year ago

I can't seem to reproduce this anymore. I'm not sure what was I was experiencing.

@addyess thanks for closing!