Delta Backup Failed invalid argument

DeOccultist

I'm running xo-server 5.74.0 community edition.
I have a delta back up job set up as follows for 3 VMs:
Full backup interval 2
Weekly Backup
Backp Retention 3
SMB remote

When I run the backup initially it will succeed on subsequent runs it will have the following errors.

VM 1 Error:

     Snapshot
        Start: Mar 14, 2021, 2:10:00 PM
        End: Mar 14, 2021, 2:10:02 PM
        128 XCP-ng 243
            transfer
            Start: Mar 14, 2021, 2:10:03 PM
            End: Mar 14, 2021, 2:42:25 PM
            Duration: 32 minutes
            Error: EINVAL: invalid argument, open '/run/xo-server/mounts/3cf06416-31ef-4334-9aef-0dacc840b28e/xo-vm-backups/040f626c-7ff9-ad6f-9161-1510b14d52bc/vdis/70f3c3b9-aeb7-4951-82fa-b055b749c87e/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210314T031003Z.vhd'
        Start: Mar 14, 2021, 2:10:03 PM
        End: Mar 14, 2021, 2:42:25 PM
        Duration: 32 minutes
        Error: EINVAL: invalid argument, open '/run/xo-server/mounts/3cf06416-31ef-4334-9aef-0dacc840b28e/xo-vm-backups/040f626c-7ff9-ad6f-9161-1510b14d52bc/vdis/70f3c3b9-aeb7-4951-82fa-b055b749c87e/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210314T031003Z.vhd'
    
    Start: Mar 14, 2021, 2:10:00 PM
    End: Mar 14, 2021, 2:42:25 PM
    Duration: 32 minutes
    Type: delta

VM 2 Error: (First time I've seen this one)

    Snapshot
    Start: Mar 14, 2021, 2:10:00 PM
    End: Mar 14, 2021, 2:10:09 PM
    128 XCP-ng 243
        transfer
        Start: Mar 14, 2021, 2:10:09 PM
        End: Mar 14, 2021, 2:37:38 PM
        Duration: 27 minutes
        Error: footer1 !== footer2
    Start: Mar 14, 2021, 2:10:09 PM
    End: Mar 14, 2021, 2:37:38 PM
    Duration: 27 minutes
    Error: footer1 !== footer2

Start: Mar 14, 2021, 2:10:00 PM
End: Mar 14, 2021, 2:37:39 PM
Duration: 28 minutes
Type: delta

I have other Full backup jobs that run sucessfully before it which writes to the same target SMB remote.

What could be the problem?

olivierlambert

Hi!

Have you checked this? https://xen-orchestra.com/docs/community.html

DeOccultist

@olivierlambert OK so now I'm testing on a XOA trial with the same remote and back up settings and I still get this error.

I have 3 VMs, the initial run for the full back up runs fine.
Then I ran the backup manually again, this time it's the delta backup and I get the following error for one VM with a 200GB disk. The delta back up for the other two were fine.

     Snapshot
    Start: Mar 16, 2021, 4:53:35 PM
    End: Mar 16, 2021, 4:53:55 PM
    128 XCP-ng 243
        transfer
        Start: Mar 16, 2021, 4:53:55 PM
        End: Mar 16, 2021, 4:57:19 PM
        Duration: 3 minutes
        Error: EINVAL: invalid argument, open '/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/040f626c-7559-ad6f-9161-1510b14d52bc/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210316T055355Z.vhd'
    Start: Mar 16, 2021, 4:53:55 PM
    End: Mar 16, 2021, 4:57:19 PM
    Duration: 3 minutes
    Error: EINVAL: invalid argument, open '/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/040f626c-7559-ad6f-9161-1510b14d52bc/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210316T055355Z.vhd'

Start: Mar 16, 2021, 4:53:35 PM
End: Mar 16, 2021, 4:57:20 PM
Duration: 4 minutes
Type: delta

The subsequent run is a full backup and 2 success and 1 failed (different VM to the last failure).

    Snapshot
    Start: Mar 16, 2021, 5:24:59 PM
    End: Mar 16, 2021, 5:25:05 PM
    128 XCP-ng 243
        transfer
        Start: Mar 16, 2021, 5:25:05 PM
        End: Mar 16, 2021, 6:02:53 PM
        Duration: 38 minutes
        Error: EINVAL: invalid argument, open '/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/5c4e9203-9bb6-97f8-5fb2-f8a71cfe3ed2/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/698876e5-c844-41c9-bfaa-c1792a2d64d4/20210316T062505Z.vhd'
    Start: Mar 16, 2021, 5:25:05 PM
    End: Mar 16, 2021, 6:02:53 PM
    Duration: 38 minutes
    Error: EINVAL: invalid argument, open '/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/5c4e9203-9bb6-97f8-5fb2-f8a71cfe3ed2/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/698876e5-c844-41c9-bfaa-c1792a2d64d4/20210316T062505Z.vhd'

Start: Mar 16, 2021, 5:24:59 PM
End: Mar 16, 2021, 6:03:06 PM
Duration: 38 minutes
Type: full

olivierlambert

Pinging @julien-f or @badrAZ

julien-f

I need to take a look at the raw log to understand what's going on here (there is a button to download it at the top of the run status modal).

Usually EINVAL indicates a system error in the communication between the XOA and the remote.

DeOccultist

Hi @julien-f

Here is the log, Thanks.

{
  "data": {
    "mode": "delta",
    "reportWhen": "never"
  },
  "id": "1615951668943",
  "jobId": "2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2",
  "jobName": "Server1 Delta VM Backup",
  "message": "backup",
  "scheduleId": "4ddb7b35-3352-4950-b036-2774dd5847bc",
  "start": 1615951668943,
  "status": "failure",
  "tasks": [
    {
      "data": {
        "type": "VM",
        "id": "e9480144-69ce-c451-b0d8-0f6eab12aafe"
      },
      "id": "1615951668949",
      "message": "Starting backup of virtual-machine-2. (2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2)",
      "start": 1615951668949,
      "status": "success",
      "tasks": [
        {
          "id": "1615951668952",
          "message": "snapshot",
          "start": 1615951668952,
          "status": "success",
          "end": 1615951674373,
          "result": "e940bcde-54f4-394f-4766-a99e474fa815"
        },
        {
          "id": "1615951674377",
          "message": "add metadata to snapshot",
          "start": 1615951674377,
          "status": "success",
          "end": 1615951674390
        },
        {
          "id": "1615951674566",
          "message": "waiting for uptodate snapshot record",
          "start": 1615951674566,
          "status": "success",
          "end": 1615951674772
        },
        {
          "id": "1615951674897",
          "message": "start snapshot export",
          "start": 1615951674897,
          "status": "success",
          "end": 1615951674897
        },
        {
          "data": {
            "id": "67bda2f7-7a02-46ad-9102-661bb1371f3d",
            "isFull": false,
            "type": "remote"
          },
          "id": "1615951674897:1",
          "message": "export",
          "start": 1615951674897,
          "status": "success",
          "tasks": [
            {
              "id": "1615951675022",
              "message": "transfer",
              "start": 1615951675022,
              "status": "success",
              "end": 1615952626682,
              "result": {
                "size": 21532619776
              }
            },
            {
              "id": "1615952626954",
              "message": "merge",
              "start": 1615952626954,
              "status": "success",
              "end": 1615953543224,
              "result": {
                "size": 12712935424
              }
            }
          ],
          "end": 1615953543225
        },
        {
          "id": "1615953543228",
          "message": "set snapshot.other_config[xo:backup:exported]",
          "start": 1615953543228,
          "status": "success",
          "end": 1615953543268
        }
      ],
      "end": 1615953544370
    },
    {
      "data": {
        "type": "VM",
        "id": "040f626c-7559-ad6f-9161-1510b14d52bc"
      },
      "id": "1615951668952:0",
      "message": "Starting backup of virtual-machine-3. (2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2)",
      "start": 1615951668952,
      "status": "failure",
      "tasks": [
        {
          "id": "1615951668954",
          "message": "snapshot",
          "start": 1615951668954,
          "status": "success",
          "end": 1615951670908,
          "result": "2f70c2b2-5c9d-aed7-f0c1-58cb56bd5bbc"
        },
        {
          "id": "1615951670912",
          "message": "add metadata to snapshot",
          "start": 1615951670912,
          "status": "success",
          "end": 1615951670927
        },
        {
          "id": "1615951671109",
          "message": "waiting for uptodate snapshot record",
          "start": 1615951671109,
          "status": "success",
          "end": 1615951671312
        },
        {
          "id": "1615951671699",
          "message": "start snapshot export",
          "start": 1615951671699,
          "status": "success",
          "end": 1615951671699
        },
        {
          "data": {
            "id": "67bda2f7-7a02-46ad-9102-661bb1371f3d",
            "isFull": false,
            "type": "remote"
          },
          "id": "1615951671700",
          "message": "export",
          "start": 1615951671700,
          "status": "failure",
          "tasks": [
            {
              "id": "1615951671757",
              "message": "transfer",
              "start": 1615951671757,
              "status": "failure",
              "end": 1615952631601,
              "result": {
                "errno": -22,
                "code": "EINVAL",
                "syscall": "open",
                "path": "/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/040f626c-7559-ad6f-9161-1510b14d52bc/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210317T032751Z.vhd",
                "message": "EINVAL: invalid argument, open '/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/040f626c-7559-ad6f-9161-1510b14d52bc/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210317T032751Z.vhd'",
                "name": "Error",
                "stack": "Error: EINVAL: invalid argument, open '/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/040f626c-7559-ad6f-9161-1510b14d52bc/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210317T032751Z.vhd'"
              }
            }
          ],
          "end": 1615952631601,
          "result": {
            "errno": -22,
            "code": "EINVAL",
            "syscall": "open",
            "path": "/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/040f626c-7559-ad6f-9161-1510b14d52bc/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210317T032751Z.vhd",
            "message": "EINVAL: invalid argument, open '/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/040f626c-7559-ad6f-9161-1510b14d52bc/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210317T032751Z.vhd'",
            "name": "Error",
            "stack": "Error: EINVAL: invalid argument, open '/run/xo-server/mounts/67bda2f7-7a02-46ad-9102-661bb1371f3d/xo-vm-backups/040f626c-7559-ad6f-9161-1510b14d52bc/vdis/2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2/1783e9d6-ca8c-4e90-8b81-9a4720ec7979/20210317T032751Z.vhd'"
          }
        },
        {
          "id": "1615952631605",
          "message": "set snapshot.other_config[xo:backup:exported]",
          "start": 1615952631605,
          "status": "success",
          "end": 1615952631613
        }
      ],
      "end": 1615952632581
    },
    {
      "data": {
        "type": "VM",
        "id": "5c4e9203-9bb6-97f8-5fb2-f8a71cfe3ed2"
      },
      "id": "1615951668954:0",
      "message": "Starting backup of virtual-machine-1. (2c73dfcf-46b4-40a1-9cd3-d4f08dd42aa2)",
      "start": 1615951668954,
      "status": "success",
      "tasks": [
        {
          "id": "1615951668954:1",
          "message": "snapshot",
          "start": 1615951668954,
          "status": "success",
          "end": 1615951694024,
          "result": "11a9f248-aee3-d662-69f3-5ef5cc2dbda4"
        },
        {
          "id": "1615951694029",
          "message": "add metadata to snapshot",
          "start": 1615951694029,
          "status": "success",
          "end": 1615951694046
        },
        {
          "id": "1615951694219",
          "message": "waiting for uptodate snapshot record",
          "start": 1615951694219,
          "status": "success",
          "end": 1615951694423
        },
        {
          "id": "1615951694636",
          "message": "start snapshot export",
          "start": 1615951694636,
          "status": "success",
          "end": 1615951694637
        },
        {
          "data": {
            "id": "67bda2f7-7a02-46ad-9102-661bb1371f3d",
            "isFull": true,
            "type": "remote"
          },
          "id": "1615951694638",
          "message": "export",
          "start": 1615951694638,
          "status": "success",
          "tasks": [
            {
              "id": "1615951694839",
              "message": "transfer",
              "start": 1615951694839,
              "status": "success",
              "end": 1615953319846,
              "result": {
                "size": 50652661760
              }
            },
            {
              "id": "1615953320215",
              "message": "merge",
              "start": 1615953320215,
              "status": "success",
              "end": 1615953320215,
              "result": {
                "size": 0
              }
            }
          ],
          "end": 1615953320215
        },
        {
          "id": "1615953320218",
          "message": "set snapshot.other_config[xo:backup:exported]",
          "start": 1615953320218,
          "status": "success",
          "end": 1615953320224
        }
      ],
      "end": 1615953333146
    }
  ],
  "end": 1615953544371
}

julien-f

@deoccultist Not much I can add there, it looks like a system error between your XOA and the remote.

What kind of remote are you using?
Does this happen often?
Have you tried restarting xo-server or the OS?