Database corruption after "lxc move" failure

LXD
1

Hi all,

I have tried to move LXD container from one to another node (both have zfs as backend). Container was stopped first (because live migration issues). This is an error from lxc move CT --target NODE (and I know why it has happen – here is important that operation has died somewhere in the middle):

Error: Copy instance operation failed: Failed instance creation: Error transferring instance data: Failed to run: zfs set refquota=16106127360 .../containers/lxd-move-of-4ebf8402-5ba4-4d49-a311-bcb2c9cbd5e9: cannot set property for '.../containers/lxd-move-of-4ebf8402-5ba4-4d49-a311-bcb2c9cbd5e9': size is less than current used or reserved space

After that failure, zfs dataset ‘…/containers/lxd-move-of-4ebf8402-5ba4-4d49-a311-bcb2c9cbd5e9’ (of course) was not removed from target node, so I did it manually…

Was that mistake?
Now, I cannot either copy/move that container within same cluster. When trying again, there is another error message:

Error: Copy instance operation failed: Failed instance creation: Error transferring instance data: Got error reading migration source: websocket: close 1000 (normal)

Not sure where to look for solution. From database I see lot of:

:; lxd sql global "select count(*) 'orphan entries?' from instances_config where id not in (select id from instances);"
+-----------------+
| orphan entries? |
+-----------------+
| 1033            |
+-----------------+

Any suggestions?
Regards.

2

I think that query isn’t useful as we would not expect the id in the instances_config table to align with the id in the instances table.

Have you tried doing lxc delete <instance> on the target server (I’m presuming the old instance still exists on the source)? And then trying the move again?

Do you know why the error is occurring btw?

Finally, what version of LXD is this?

3

Regarding your questions:

Well, there is no such instance on target… So, nothing to delete (was only zfs dataset present: lxd-move-of-UUID, which I have deleted)

It was related to lxd snapshots of source CT and its size and some limits we have set on zfs datasets (combination of all options + big dataset size). I think we have fixed it, but still getting error when trying to move.

Is there option to see exactly what is show stopper? (DEBUG, VERBOSE, etc)?

Was 5.0 when problem happen! (BTW, we have updated to 5.2 today, but no luck).

Regards.

4

You will likely benefit from this PR when it gets released that will better propagate migration errors:

Are both servers running LXD 5.2?

Can you show output of lxc config show <instance> --expanded, lxc info <instance> and lxc storage list <pool> please?

5

Yes

architecture: x86_64
config:
  boot.host_shutdown_timeout: "120"
  environment.lxdMosaicPullMetrics: "y"
  limits.memory: 8192MB
  limits.processes: "17384"
  user.managed: "true"
  volatile.eth0.host_name: veth8d57dfcb
  volatile.eth0.hwaddr: 00:16:3e:50:22:52
  volatile.idmap.base: "0"
  volatile.idmap.current: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.idmap.next: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.idmap: '[{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}]'
  volatile.last_state.power: RUNNING
  volatile.uuid: ced7af97-f2a8-ef34-d85e-ad8e7d3e02e2
devices:
  eth0:
    name: eth0
    nictype: bridged
    parent: br0
    type: nic
  root:
    path: /
    pool: POOL
    size: 20GiB
    type: disk
ephemeral: false
profiles:
- lxdMosaicPullMetrics
- default
stateful: false
description: ""

Name: <instance>            
Status: RUNNING 
Type: container      
Architecture: x86_64
Location: SOURCE_HOST
PID: 4097029   
Created: 2021/09/13 11:37 CEST
Last Used: 2022/06/09 15:22 CEST
                                                   
Resources:              
  Processes: 319   
  Disk usage:
    root: 10.15GiB
  CPU usage:                                                                                          
    CPU usage (in seconds): 558                                                                       
  Memory usage:                                                                                       
    Memory (current): 2.18GiB                                                                         
    Memory (peak): 3.21GiB                                                                            
  Network usage:                                                                                      
    docker0:                                                                                          
      Type: broadcast                                                                                 
      State: UP                                                                                       
      MAC address: 02:42:57:54:fb:44                                                                  
      MTU: 1500                                                                                       
      Bytes received: 1.59MB                                                                          
      Bytes sent: 164.48MB                                                                            
      Packets received: 15491                                                                         
      Packets sent: 24549                                                                             
      IP addresses:                                                                                   
        inet:  172.17.0.1/16 (global)                                                                 
    eth0:                                                                                             
      Type: broadcast                                                                                 
      State: UP                                                                                       
      Host interface: veth8d57dfcb                                                                    
      MAC address: 00:16:3e:50:22:52                                                                  
      MTU: 1496                                                                                       
      Bytes received: 502.77MB
      Bytes sent: 79.84MB
      Packets received: 136730
      Packets sent: 70088
      IP addresses:
        inet:  192.168.220.126/23 (global)
    lo:
      Type: loopback
      State: UP
      MTU: 65536
      Bytes received: 0B
      Bytes sent: 0B
      Packets received: 0
      Packets sent: 0
      IP addresses:
        inet:  127.0.0.1/8 (local)
    veth7bf2568:
      Type: broadcast
      State: UP
      MAC address: f2:36:c1:95:49:3b
      MTU: 1500
      Bytes received: 68.78kB
      Bytes sent: 8.64MB
      Packets received: 975
      Packets sent: 1546
      IP addresses:

Snapshots:
+----------------------+-----------------------+------------+----------+
|         NAME         |       TAKEN AT        | EXPIRES AT | STATEFUL |
+----------------------+-----------------------+------------+----------+
| auto-20220528-230451 | 2022/05/29 01:04 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220531-230146 | 2022/06/01 01:01 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220604-230350 | 2022/06/05 01:03 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220606-230150 | 2022/06/07 01:01 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220607-230113 | 2022/06/08 01:01 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220608-230150 | 2022/06/09 01:01 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220609-100122 | 2022/06/09 12:01 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220609-110207 | 2022/06/09 13:02 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220609-120128 | 2022/06/09 14:01 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+
| auto-20220609-130121 | 2022/06/09 15:01 CEST |            | NO       |
+----------------------+-----------------------+------------+----------+

+------+--------+-------------+---------+---------+
| NAME | DRIVER | DESCRIPTION | USED BY |  STATE  |
+------+--------+-------------+---------+---------+
| POOL | zfs    |             | 135     | CREATED |
+------+--------+-------------+---------+---------+

NOTE: I have replaced some names/IDs (POOL, SOURCE_HOST) - not showing instance name as well

Regards.

6

Sorry I meant lxc storage volume list POOL

7

Well, it is full of entries like these (not pasting everything, because I think it is not important):

+----------------------------+------------------------------------------------------------------+-------------+--------------+---------+----------+                                                          
|            TYPE            |                               NAME                               | DESCRIPTION | CONTENT-TYPE | USED BY | LOCATION |                                                          
+----------------------------+------------------------------------------------------------------+-------------+--------------+---------+----------+                                                          
| container                  | CTNAME                                                           |             | filesystem   | 1       | TARGET   |                                                          
+----------------------------+------------------------------------------------------------------+-------------+--------------+---------+----------+                                                          
| container (snapshot)       | CTNAME/auto-20220528-230106                                      |             | filesystem   | 1       | TARGET   |
...

Each container has several snapshots and end each one is content-type filesystem, used by 1
Regards.

8

Can I see the full list for the problem container please?

9

Hi, sure (names mangled):

+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container                  | INSTANCE                                                 |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220528-230451                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220531-230146                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220604-230350                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220607-230113                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220608-230150                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220609-230145                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220610-030141                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220610-040138                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220610-050155                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
| container (snapshot)       | INSTANCE/auto-20220610-060143                            |             | filesystem   | 1       | SOURCE   |
+----------------------------+----------------------------------------------------------+-------------+--------------+---------+----------+
10

OK good so we have the same amount of instance snapshot DB records (shown in lxc info <instance>) as storage volume snapshot DB records (shown in lxc storage volume ls <pool>) for that instance.

Can you show the output of sudo zfs list in source and target, I want to check there’s no left overs of the container left?

11

As I have mentioned above: I have destroyed lxd-move-of-UUID zfs dataset from the TARGET node…
On the SOURCE node, there is only one zfs dataset, and that one belongs to INSTANCE.

Just as a side note:
lxc copy works (when INSTANCE is down) – which is to be expected as it is copied under new name.

When this is solved, we might have more details when it has failed (i STILL EXPECT FAILURE):

Regards…

12

I’m confused.

Why do you expect failure when copying but not moving?
Does move work when the instance is stopped?

13

Huh,
maybe I did not wrote properly/clear enough (INSTANCE is down):

  • lxc move fails
  • lxc copy works

Somehow, I still think that there is some problem in database:

lxd sql global "select * from instances_config where instance_id=779;" 
+-------+-------------+---------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------+
|  id   | instance_id |            key            |                                                                            value                                                                            |
+-------+-------------+---------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 41729 | 779         | user.managed              | true                                                                                                                                                        |
| 41759 | 779         | volatile.eth0.host_name   | veth8d57dfcb                                                                                                                                                |
| 41726 | 779         | volatile.eth0.hwaddr      | 00:16:3e:50:22:52                                                                                                                                           |
| 41731 | 779         | volatile.idmap.base       | 0                                                                                                                                                           |
| 41727 | 779         | volatile.idmap.current    | [{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}] |
| 41732 | 779         | volatile.idmap.next       | [{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}] |
| 41728 | 779         | volatile.last_state.idmap | [{"Isuid":true,"Isgid":false,"Hostid":1000000,"Nsid":0,"Maprange":1000000000},{"Isuid":false,"Isgid":true,"Hostid":1000000,"Nsid":0,"Maprange":1000000000}] |
| 41760 | 779         | volatile.last_state.power | RUNNING                                                                                                                                                     |
| 41734 | 779         | volatile.uuid             | ced7af97-f2a8-ef34-d85e-ad8e7d3e02e2                                                                                                                        |
+-------+-------------+---------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------+

which corresponds to:

:; lxc config show INSTANCE | grep uuid
  volatile.uuid: ced7af97-f2a8-ef34-d85e-ad8e7d3e02e2

From journalctl -u snap.lxd.daemon.service, we see error (when trying move):

msg="Failed initialising instance" err="Failed to set volatile config: FOREIGN KEY constraint failed" instance=lxd-move-of-ced7af97-f2a8-ef34-d85e-ad8e7d3e02e2/auto-20220528-230451 project=default type=container

It tries to send snapshot as well (that is 1st one, from list above). So, I will try (again) with --instance-only switch, and report…

14

Nope (or I am using wrong syntax):

:; lxc stop $INSTANCE

:; lxc move --instance-only --target $TARGET $INSTANCE
Error: The --instance-only flag can't be used with --target

:; lxc move $INSTANCE $TARGET:$INSTANCE --instance-only
Error: The remote "$TARGET" doesn't exist
15

Got you, copy works, move fails.

Let me see if I can reproduce.

16

Which host does this occur on? The target?

17

I suspect its failing here:

As the log error you are getting is from here when creating the instance snapshot record:

And that would then explain why the migration disconnects.

The error itself is likely coming from:

The question is what scenario are you getting DB key conflicts.

19

Yes, that error occurs on TARGET node

20

We have 2 possible (potential) causes:

  • quota was not set on SOURCE dataset – so we set it (after few shapshots were created. Older snapshot were huge 5-6 of them, each 50+ GB in size)
  • and (not sure, but very likely) we set zfs ref_quota some time in between 2 snapshots
  • then, I have tried to move node (sorry, but cannot be more precise, as I was not saving ssh session)

I will try to create lxd-move-of-UUID dataset on TARGET note, with same attributes which have SOURCE one, and try move again. Seems it is failing to create one (to see what will happen if there is already dataset there.)

21

Its failing to create the volatile config key entries for the lxd-move-of-ced7af97-f2a8-ef34-d85e-ad8e7d3e02e2/auto-20220528-230451 instance snapshot in the instances_config table.