LXD crashed via panic

LXD
1

I’ve encountered a panic crash of LXD when connecting to the operation/websocket API endpoint. I’ve yet to reliable recreate it, though I’ve had it happen 3 times lately.

I wanted to submit here just in case I’m doing something improper. However, I can submit to Github issues if it turns out to be a real bug if you’d like me to.

Thanks LXD team for all your hard work and phenomenal release schedule lately!

Scenario:

  • LXD version 3.23 running in debug mode on Ubuntu 18.04.2 LTS (container is also Ubuntu)
  • It appears to happen occasionally when I try to connect to an already closed websocket (possibly improperly closed?) with an old (already used) secret param. I haven’t been able to recreate it yet using those steps though.

First crash output

DBUG[03-22|17:58:18] Allowing untrusted GET                   ip=127.0.0.1:35560 url="/1.0/operations/c882658c-5825-401f-b30f-76639e1d789c/websocket?secret=8e663fe28d92b85bf529cd0288a84c6984fc620543d427388aeb6b8de41a29d9"
DBUG[03-22|17:58:18] Connected websocket Operation: c882658c-5825-401f-b30f-76639e1d789c 
DBUG[03-22|17:58:18] Handled websocket Operation: c882658c-5825-401f-b30f-76639e1d789c 
DBUG[03-22|17:58:18] Instance process started                 instance=c2 PID=6429
DBUG[03-22|17:58:18] Started mirroring websocket              instance=c2 PID=6429
DBUG[03-22|17:58:18] Interactive child process handler started instance=c2 PID=6429
DBUG[03-22|18:03:07] Got error getting next reader websocket: close 1006 (abnormal closure): unexpected EOF 
DBUG[03-22|18:09:55] Allowing untrusted GET                   url="/1.0/operations/c882658c-5825-401f-b30f-76639e1d789c/websocket?secret=8e663fe28d92b85bf529cd0288a84c6984fc620543d427388aeb6b8de41a29d9" ip=127.0.0.1:35562
DBUG[03-22|18:09:55] Connected websocket Operation: c882658c-5825-401f-b30f-76639e1d789c 
panic: close of closed channel

goroutine 11022 [running]:
main.(*execWs).Connect(0xc0006e5d60, 0xc0001e9000, 0xc0001e8e00, 0x15a48c0, 0xc00063c620, 0x20300000000000, 0x7f6f064d4fff)
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance_exec.go:95 +0x329
github.com/lxc/lxd/lxd/operations.(*Operation).Connect.func1(0xc0001e8e00, 0x15a48c0, 0xc00063c620, 0xc0001e9000, 0xc000080720)
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/operations/operations.go:356 +0x71
created by github.com/lxc/lxd/lxd/operations.(*Operation).Connect
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/operations/operations.go:355 +0xed

Second crash output

DBUG[03-26|19:59:02] Allowing untrusted GET                   ip=127.0.0.1:41356 url="/1.0/operations/990eb355-584a-43d6-8d22-3aab0e1eed42/websocket?secret=06e25cb3008b1c96adbfc40474e2b803bfef887978c29c0ab19894cded781f75"
DBUG[03-26|19:59:02] Connected websocket Operation: 990eb355-584a-43d6-8d22-3aab0e1eed42 
DBUG[03-26|19:59:02] Handled websocket Operation: 990eb355-584a-43d6-8d22-3aab0e1eed42 
DBUG[03-26|19:59:03] Instance process started                 instance=c2 PID=10158
DBUG[03-26|19:59:03] Started mirroring websocket              instance=c2 PID=10158
DBUG[03-26|19:59:03] Interactive child process handler started instance=c2 PID=10158
DBUG[03-26|19:59:28] Got error getting next reader websocket: close 1006 (abnormal closure): unexpected EOF 
DBUG[03-26|20:01:00] Allowing untrusted GET                   url="/1.0/operations/990eb355-584a-43d6-8d22-3aab0e1eed42/websocket?secret=06e25cb3008b1c96adbfc40474e2b803bfef887978c29c0ab19894cded781f75" ip=127.0.0.1:41358
DBUG[03-26|20:01:00] Connected websocket Operation: 990eb355-584a-43d6-8d22-3aab0e1eed42 
panic: close of closed channel

goroutine 8717 [running]:
main.(*execWs).Connect(0xc00053d4a0, 0xc000b5a100, 0xc000b5a400, 0x157f640, 0xc0000fc540, 0x0, 0x0)
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance_exec.go:95 +0x329
github.com/lxc/lxd/lxd/operations.(*Operation).Connect.func1(0xc000b5a400, 0x157f640, 0xc0000fc540, 0xc000b5a100, 0xc000872480)
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/operations/operations.go:356 +0x71
created by github.com/lxc/lxd/lxd/operations.(*Operation).Connect
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/operations/operations.go:355 +0xed

Third crash output

DBUG[03-26|20:02:14] Allowing untrusted GET                   url="/1.0/operations/981da05e-fcce-4e9b-b0aa-3638d71c9b19/websocket?secret=5dac5124bfb34844e56f6c87f2ee0dc8e33491a2347448c16e18e2290ba47a11" ip=127.0.0.1:41396
DBUG[03-26|20:02:14] Connected websocket Operation: 981da05e-fcce-4e9b-b0aa-3638d71c9b19 
DBUG[03-26|20:02:14] Handled websocket Operation: 981da05e-fcce-4e9b-b0aa-3638d71c9b19 
DBUG[03-26|20:02:14] Instance process started                 instance=c2 PID=10583
DBUG[03-26|20:02:14] Interactive child process handler started instance=c2 PID=10583
DBUG[03-26|20:02:14] Started mirroring websocket              instance=c2 PID=10583
DBUG[03-26|20:03:19] Got error getting next reader websocket: close 1006 (abnormal closure): unexpected EOF 
DBUG[03-26|20:06:06] Allowing untrusted GET                   url="/1.0/operations/981da05e-fcce-4e9b-b0aa-3638d71c9b19/websocket?secret=5dac5124bfb34844e56f6c87f2ee0dc8e33491a2347448c16e18e2290ba47a11" ip=127.0.0.1:41398
DBUG[03-26|20:06:06] Connected websocket Operation: 981da05e-fcce-4e9b-b0aa-3638d71c9b19 
panic: close of closed channel

goroutine 952 [running]:
main.(*execWs).Connect(0xc000168d20, 0xc0009ec600, 0xc000164300, 0x157f640, 0xc0001668c0, 0xc000591b00, 0x200000003)
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance_exec.go:95 +0x329
github.com/lxc/lxd/lxd/operations.(*Operation).Connect.func1(0xc000164300, 0x157f640, 0xc0001668c0, 0xc0009ec600, 0xc000292e40)
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/operations/operations.go:356 +0x71
created by github.com/lxc/lxd/lxd/operations.(*Operation).Connect
        /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/operations/operations.go:355 +0xed
2

Thanks I’ll take a look at this.

3

Do you have an example of what you’re doing when it occurs?

4

I dont think you should attempt to reconnect using the same token if you’ve already connected previously.

@stgraber can you confirm that please?

If so, then this PR should block those reconnects:

5

The first crash occurred when I was using the command line tool websocat to interact with the websocket connection. websocat -kvb <url> are the options I’m using. It’s been working well.

A few times I killed the websocat tool by using ctrl+c and also by accident re-used an operation uuid/secret token again, but some combination of that scenario caused the crash.

Hope that helps and thank you for responding so quickly!

6

I’m able to re-create the crash now using these steps:

  • Generate new exec operation via API 1.0/containers/[name]/exec to run bash in the container
  • Use uuid / secret token with websocat and interact with socket
  • Ctrl + C websocat and then try to run the same command again (same uuid/token)
  • Results in the crash

Now if I close the connection by issuing exit to the websocket (which is issued to bash in the container), the socket connection is closed correctly and if I try to reconnect with the same command (uuid/secret) I get the normal error from LXD:

DBUG[03-26|21:46:48] Allowing untrusted GET                   url="/1.0/operations/2dbc31eb-e34d-4a47-bc0e-8ee6d9f00df4/websocket?secret=65bb5525ff46f1ab72fbff9be2628629e7173d3b6587725dc25ae55b36fb519e" ip=127.0.0.1:41642
DBUG[03-26|21:47:00] Allowing untrusted GET                   url="/1.0/operations/2dbc31eb-e34d-4a47-bc0e-8ee6d9f00df4/websocket?secret=65bb5525ff46f1ab72fbff9be2628629e7173d3b6587725dc25ae55b36fb519e" ip=127.0.0.1:41644
DBUG[03-26|21:47:00] Database error: &errors.errorString{s:"No such object"}