XCP-ng
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Groups
    • Register
    • Login

    XO task watcher issue/CR broken

    Scheduled Pinned Locked Moved Solved Xen Orchestra
    71 Posts 6 Posters 15.2k Views 7 Watching
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • julien-fJ Offline
      julien-f Vates 🪐 Co-Founder XO Team @Andrew
      last edited by

      @Andrew I don't reproduce the issue on my end.

      A 1 Reply Last reply Reply Quote 0
      • A Offline
        Andrew Top contributor @julien-f
        last edited by

        @julien-f I happens to me every time with the new XO source... when I use the older version it works correctly.

        XO just does not see the transfer task complete. I don't see any errors or timeouts.

        When I reload the XO server process I get:

        Feb 08 12:39:52 xo1 systemd[1]: Reloading.
Feb 08 12:39:52 xo1 xo-server[389]: 2023-02-08T17:39:52.416Z xo:main INFO SIGTERM caught, closing…
Feb 08 12:39:52 xo1 systemd[1]: Stopping XO Server...
Feb 08 12:39:52 xo1 xo-server[389]: 2023-02-08T17:39:52.427Z xo:api WARN admin | backupNg.runJob(...) [28m] =!> Error: worker exited with code null
Feb 08 12:39:52 xo1 xo-server[389]: 2023-02-08T17:39:52.442Z xo:main WARN WebSocket send: {
Feb 08 12:39:52 xo1 xo-server[389]:   error: Error: The socket was closed while data was being compressed
Feb 08 12:39:52 xo1 xo-server[389]:       at /opt/xo/xo-builds/xen-orchestra-202302081151/node_modules/ws/lib/sender.js:410:21
Feb 08 12:39:52 xo1 xo-server[389]:       at /opt/xo/xo-builds/xen-orchestra-202302081151/node_modules/ws/lib/permessage-deflate.js:326:9
Feb 08 12:39:52 xo1 xo-server[389]:       at PerMessageDeflate.cleanup (/opt/xo/xo-builds/xen-orchestra-202302081151/node_modules/ws/lib/permessage-deflate.js:143:9)
Feb 08 12:39:52 xo1 xo-server[389]:       at WebSocket.emitClose (/opt/xo/xo-builds/xen-orchestra-202302081151/node_modules/ws/lib/websocket.js:253:57)
Feb 08 12:39:52 xo1 xo-server[389]:       at TLSSocket.socketOnClose (/opt/xo/xo-builds/xen-orchestra-202302081151/node_modules/ws/lib/websocket.js:1260:15)
Feb 08 12:39:52 xo1 xo-server[389]:       at TLSSocket.emit (node:events:525:35)
Feb 08 12:39:52 xo1 xo-server[389]:       at TLSSocket.patchedEmit [as emit] (/opt/xo/xo-builds/xen-orchestra-202302081151/@xen-orchestra/log/configure.js:52:17)
Feb 08 12:39:52 xo1 xo-server[389]:       at node:net:322:12
Feb 08 12:39:52 xo1 xo-server[389]:       at Socket.done (node:_tls_wrap:588:7)
Feb 08 12:39:52 xo1 xo-server[389]:       at Object.onceWrapper (node:events:628:26)
Feb 08 12:39:52 xo1 xo-server[389]:       at Socket.emit (node:events:525:35)
Feb 08 12:39:52 xo1 xo-server[389]:       at Socket.patchedEmit [as emit] (/opt/xo/xo-builds/xen-orchestra-202302081151/@xen-orchestra/log/configure.js:52:17)
Feb 08 12:39:52 xo1 xo-server[389]:       at TCP.<anonymous> (node:net:322:12)
Feb 08 12:39:52 xo1 xo-server[389]:       at TCP.callbackTrampoline (node:internal/async_hooks:130:17)
Feb 08 12:39:52 xo1 xo-server[389]: }
Feb 08 12:39:52 xo1 xo-server[389]: 2023-02-08T17:39:52.908Z xo:main INFO bye :-)
Feb 08 12:39:52 xo1 systemd[1]: xo-server.service: Succeeded.
Feb 08 12:39:52 xo1 systemd[1]: Stopped XO Server.
Feb 08 12:39:52 xo1 systemd[1]: xo-server.service: Consumed 5min 16.239s CPU time.
        julien-fJ 1 Reply Last reply Reply Quote 0
        • julien-fJ Offline
          julien-f Vates 🪐 Co-Founder XO Team @Andrew
          last edited by

          @Andrew Just tried with a fresh build of XO and I don't see any problems.

          What's your job config?

          A 1 Reply Last reply Reply Quote 0
          • A Offline
            Andrew Top contributor @julien-f
            last edited by

            @julien-f Here's the backup info for the CR job. It works correctly on XO commit bf51b.

            backupjob.jpg

            julien-fJ 1 Reply Last reply Reply Quote 0
            • julien-fJ Offline
              julien-f Vates 🪐 Co-Founder XO Team @Andrew
              last edited by

              @Andrew What's your Node version?

              A 1 Reply Last reply Reply Quote 0
              • A Offline
                Andrew Top contributor @julien-f
                last edited by

                @julien-f node.js v18.14.0 on Debian 11.6

                julien-fJ 1 Reply Last reply Reply Quote 0
                • julien-fJ Offline
                  julien-f Vates 🪐 Co-Founder XO Team @Andrew
                  last edited by

                  @Andrew What kind of remote are you using? And with which configuration (encryption, multiple data blocks, etc)?

                  julien-fJ 1 Reply Last reply Reply Quote 0
                  • julien-fJ Offline
                    julien-f Vates 🪐 Co-Founder XO Team @julien-f
                    last edited by

                    My bad, there is no remote with CR 😂

                    I have no idea what's going though… 😭

                    A 1 Reply Last reply Reply Quote 0
                    • A Offline
                      Andrew Top contributor @julien-f
                      last edited by

                      @julien-f I was just going to say it's another host local storage, not a remote. Desination host is not in the same pool but is on the same 10GB LAN. All hosts are 8.2.1.

                      julien-fJ 1 Reply Last reply Reply Quote 0
                      • julien-fJ Offline
                        julien-f Vates 🪐 Co-Founder XO Team @Andrew
                        last edited by

                        @Andrew I'm unable to reproduce on my end 😞

                        If you can reproduce with an official XOA, open a support tunnel and I'll investigate further.

                        A 1 Reply Last reply Reply Quote 0
                        • A Offline
                          Andrew Top contributor @julien-f
                          last edited by

                          @julien-f I loaded XOA (5.109.0) but it's not new enough to include to problematic code that cause problems in XO source.

                          julien-fJ 1 Reply Last reply Reply Quote 0
                          • A Andrew referenced this topic on
                          • julien-fJ Offline
                            julien-f Vates 🪐 Co-Founder XO Team @Andrew
                            last edited by

                            @Andrew If you open a support tunnel, I can deploy a sources XO in your appliance.

                            A 1 Reply Last reply Reply Quote 0
                            • A Offline
                              Andrew Top contributor @julien-f
                              last edited by

                              @julien-f ok.

                              julien-fJ 1 Reply Last reply Reply Quote 0
                              • julien-fJ Offline
                                julien-f Vates 🪐 Co-Founder XO Team @Andrew
                                last edited by

                                @Andrew Please test the branch cr-issue and tell me if that helps.

                                A 1 Reply Last reply Reply Quote 0
                                • A Offline
                                  Andrew Top contributor @julien-f
                                  last edited by

                                  @julien-f cr-issue branch commit 27d81 resolved this new CR problem for me. Thanks!

                                  julien-fJ 1 Reply Last reply Reply Quote 0
                                  • julien-fJ Offline
                                    julien-f Vates 🪐 Co-Founder XO Team @Andrew
                                    last edited by

                                    @Andrew I need to understand why it's working now 😅

                                    Which version of XCP-ng/XenServer are you using as source and as the target of the CR?

                                    julien-fJ 1 Reply Last reply Reply Quote 0
                                    • GheppyG Offline
                                      Gheppy
                                      last edited by Gheppy

                                      This commit 27d81 is working for me to.
                                      XCP-ng is 8.2.1, up to date

                                      julien-fJ 1 Reply Last reply Reply Quote 0
                                      • julien-fJ Offline
                                        julien-f Vates 🪐 Co-Founder XO Team @Gheppy
                                        last edited by julien-f

                                        @Andrew & @Gheppy: I've just pushed a new commit in the cr-issue branch which adds some debug logs, it adds something like that:

                                        putResource(b1imtu1j0y): taskRef: OpaqueRef:10eb89fd-d31e-495b-955d-672c61a4ea48
putResource(b1imtu1j0y): useHack: false
putResource(b1imtu1j0y): body#end
putResource(b1imtu1j0y): request#unpipe
putResource(b1imtu1j0y): request#prefinish
putResource(b1imtu1j0y): request#finish
putResource(b1imtu1j0y): response#resume
putResource(b1imtu1j0y): body#close
putResource(b1imtu1j0y): response#readable
putResource(b1imtu1j0y): response#end
putResource(b1imtu1j0y): response#close
putResource(b1imtu1j0y): request#close

                                        If you could try it and show me the output, that would help me understand what's going on 🙂

                                        A 1 Reply Last reply Reply Quote 1
                                        • olivierlambertO Offline
                                          olivierlambert Vates 🪐 Co-Founder CEO
                                          last edited by

                                          Eager to read the output, it's weird we can't reproduce here, there's something 🤔

                                          1 Reply Last reply Reply Quote 0
                                          • GheppyG Offline
                                            Gheppy
                                            last edited by Gheppy

                                            @julien-f
                                            with command -- journalctl -u xo-server -f -n 70

                                            Feb 10 13:33:31 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): body#drain
Feb 10 13:33:31 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): body#drain
Feb 10 13:33:31 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): body#drain
Feb 10 13:33:31 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): body#drain
Feb 10 13:33:31 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): body#drain
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): response#readable
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): request#close
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): request#unpipe
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): body#error
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): body#unpipe
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): body#close
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): response#resume
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): response#end
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(ty99546973n): response#close
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): response#readable
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): request#close
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): request#unpipe
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): body#error
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): body#unpipe
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): body#close
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): response#resume
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): response#end
Feb 10 13:33:32 tb-xoce-e-19 xo-server[32712]: putResource(vcybyae8pn): response#close
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]: [WARN] plugin transport-email: Error: No recipients defined
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection._formatError (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:790:19)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection._setEnvelope (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:1007:34)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection.send (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:621:14)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at sendMessage (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-transport/index.js:228:28)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at /opt/xen-orchestra/node_modules/nodemailer/lib/smtp-transport/index.js:289:21
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection.<anonymous> (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:213:17)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at Object.onceWrapper (node:events:627:28)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection.emit (node:events:513:28)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection.patchedEmit [as emit] (/opt/xen-orchestra/@xen-orchestra/log/configure.js:52:17)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection._actionEHLO (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:1331:14)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection._processResponse (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:953:20)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at SMTPConnection._onData (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:755:14)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at Socket.SMTPConnection._onSocketData (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:193:44)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at Socket.emit (node:events:513:28)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at Socket.patchedEmit [as emit] (/opt/xen-orchestra/@xen-orchestra/log/configure.js:52:17)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at addChunk (node:internal/streams/readable:324:12)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at readableAddChunk (node:internal/streams/readable:297:9)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at Socket.Readable.push (node:internal/streams/readable:234:10)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at TCP.onStreamRead (node:internal/stream_base_commons:190:23)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     at TCP.callbackTrampoline (node:internal/async_hooks:130:17)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]: 2023-02-10T11:34:05.207Z xo:xo-server WARN possibly unhandled rejection {
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:   error: Error: No recipients defined
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection._formatError (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:790:19)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection._setEnvelope (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:1007:34)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection.send (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:621:14)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at sendMessage (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-transport/index.js:228:28)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at /opt/xen-orchestra/node_modules/nodemailer/lib/smtp-transport/index.js:289:21
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection.<anonymous> (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:213:17)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at Object.onceWrapper (node:events:627:28)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection.emit (node:events:513:28)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection.patchedEmit [as emit] (/opt/xen-orchestra/@xen-orchestra/log/configure.js:52:17)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection._actionEHLO (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:1331:14)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection._processResponse (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:953:20)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at SMTPConnection._onData (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:755:14)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at Socket.SMTPConnection._onSocketData (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:193:44)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at Socket.emit (node:events:513:28)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at Socket.patchedEmit [as emit] (/opt/xen-orchestra/@xen-orchestra/log/configure.js:52:17)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at addChunk (node:internal/streams/readable:324:12)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at readableAddChunk (node:internal/streams/readable:297:9)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at Socket.Readable.push (node:internal/streams/readable:234:10)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at TCP.onStreamRead (node:internal/stream_base_commons:190:23)
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:       at TCP.callbackTrampoline (node:internal/async_hooks:130:17) {
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     code: 'EENVELOPE',
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:     command: 'API'
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]:   }
Feb 10 13:34:05 tb-xoce-e-19 xo-server[32617]: }

                                            On backup log I have this

                                            {
  "data": {
    "mode": "delta",
    "reportWhen": "always"
  },
  "id": "1676028066913",
  "jobId": "dca46bf4-dca6-4e07-8dab-dc644d6f47c1",
  "jobName": "productie-Sincronizare-Activa-NU-STERGE",
  "message": "backup",
  "scheduleId": "118e0756-3588-4d70-97d8-f6705bc3785f",
  "start": 1676028066913,
  "status": "success",
  "infos": [
    {
      "data": {
        "vms": [
          "629bdfeb-7700-561c-74ac-e151068721c2"
        ]
      },
      "message": "vms"
    }
  ],
  "tasks": [
    {
      "data": {
        "type": "VM",
        "id": "629bdfeb-7700-561c-74ac-e151068721c2"
      },
      "id": "1676028068026:0",
      "message": "backup VM",
      "start": 1676028068026,
      "status": "success",
      "tasks": [
        {
          "id": "1676028068072",
          "message": "snapshot",
          "start": 1676028068072,
          "status": "success",
          "end": 1676028071566,
          "result": "6f52cc17-328e-589a-82a8-c217ac34d6f1"
        },
        {
          "data": {
            "id": "5148208b-acf6-13f3-4f36-5817e3eb6ab1",
            "isFull": false,
            "type": "SR"
          },
          "id": "1676028071568",
          "message": "export",
          "start": 1676028071568,
          "status": "success",
          "tasks": [
            {
              "id": "1676028071596",
              "message": "transfer",
              "start": 1676028071596,
              "status": "success",
              "end": 1676028094729,
              "result": {
                "size": 162336256
              }
            }
          ],
          "end": 1676028107179
        },
        {
          "data": {
            "id": "7a4829c0-e59a-726c-34bc-1a1052b0334f",
            "isFull": false,
            "type": "SR"
          },
          "id": "1676028071567",
          "message": "export",
          "start": 1676028071567,
          "status": "success",
          "tasks": [
            {
              "id": "1676028071592",
              "message": "transfer",
              "start": 1676028071592,
              "status": "success",
              "end": 1676028094954,
              "result": {
                "size": 162336256
              }
            }
          ],
          "end": 1676028110020
        }
      ],
      "end": 1676028129516
    }
  ],
  "end": 1676028129517
}
                                            julien-fJ 1 Reply Last reply Reply Quote 0
                                            • First post
                                              Last post