XO task watcher issue/CR broken
-
Once filtered, here's what I see:
putResource(hhprvsf5i): taskRef: OpaqueRef:bb9bbc77-8c88-4621-82a7-745197306c3b putResource(hhprvsf5i): useHack: false putResource(hhprvsf5i): response#readable putResource(hhprvsf5i): request#close putResource(hhprvsf5i): request#unpipe putResource(hhprvsf5i): body#error putResource(hhprvsf5i): body#unpipe putResource(hhprvsf5i): body#close putResource(hhprvsf5i): response#resume putResource(hhprvsf5i): response#end putResource(hhprvsf5i): response#closeI don't understand why there is not a
request#finishevent like in my test
-
It's probably related to the
body#errorevent.I will add more debug and will keep you posted when the branch is ready.
-
@julien-f I'll do another run after the next debug update.
-
@julien-f
Logs with commit dd1edd2519c593b06372ddec9041bd525f40ba05Feb 10 17:58:17 tb-xoce-e-19 systemd[1]: Stopping XO Server... Feb 10 17:58:17 tb-xoce-e-19 xo-server[9598]: 2023-02-10T15:58:17.143Z xo:main INFO SIGTERM caught, closing… Feb 10 17:58:17 tb-xoce-e-19 xo-server[9598]: 2023-02-10T15:58:17.181Z xo:main INFO bye :-) Feb 10 17:58:17 tb-xoce-e-19 systemd[1]: xo-server.service: Deactivated successfully. Feb 10 17:58:17 tb-xoce-e-19 systemd[1]: Stopped XO Server. Feb 10 17:58:17 tb-xoce-e-19 systemd[1]: xo-server.service: Consumed 19.958s CPU time. -- Boot 077eda8b3bde4af6b29a23add0da503a -- Feb 10 17:58:41 tb-xoce-e-19 systemd[1]: Started XO Server. Feb 10 17:59:02 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:02.632Z xo:main INFO Configuration loaded. Feb 10 17:59:02 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:02.711Z xo:main INFO Web server listening on https://0.0.0.0:443 Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:03.263Z xo:mixins:hooks WARN start failure { Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: error: Error: Command failed with exit code 5: vgchange -an Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: Logical volume ubuntu-vg/ubuntu-lv contains a filesystem in use. Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: Can't deactivate volume group "ubuntu-vg" with 1 open logical volume(s) Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: at makeError (file:///opt/xen-orchestra/packages/xo-server/node_modules/execa/lib/error.js:59:11) Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: at handlePromise (file:///opt/xen-orchestra/packages/xo-server/node_modules/execa/index.js:119:26) { Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: shortMessage: 'Command failed with exit code 5: vgchange -an', Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: command: 'vgchange -an', Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: escapedCommand: 'vgchange -an', Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: exitCode: 5, Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: signal: undefined, Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: signalDescription: undefined, Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: stdout: '', Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: stderr: ' Logical volume ubuntu-vg/ubuntu-lv contains a filesystem in use.\n' + Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: ` Can't deactivate volume group "ubuntu-vg" with 1 open logical volume(s)`, Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: failed: true, Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: timedOut: false, Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: isCanceled: false, Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: killed: false Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: } Feb 10 17:59:03 tb-xoce-e-19 xo-server[837]: } Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.300Z xo:main INFO Setting up / → /opt/xen-orchestra/packages/xo-web/dist Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.315Z xo:plugin INFO register audit Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.331Z xo:plugin INFO register auth-github Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.332Z xo:plugin INFO register auth-google Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.341Z xo:plugin INFO register auth-ldap Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.343Z xo:plugin INFO register auth-saml Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.355Z xo:plugin INFO register backup-reports Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.367Z xo:plugin INFO register load-balancer Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.368Z xo:plugin INFO register netbox Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.370Z xo:plugin INFO register perf-alert Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.379Z xo:plugin INFO register sdn-controller Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.380Z xo:plugin INFO register test-plugin Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.381Z xo:plugin INFO register transport-email Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.395Z xo:plugin INFO register transport-icinga2 Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.401Z xo:plugin INFO register transport-nagios Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.403Z xo:plugin INFO register transport-slack Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.408Z xo:plugin INFO register transport-xmpp Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.413Z xo:plugin INFO register usage-report Feb 10 17:59:05 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:05.414Z xo:plugin INFO register web-hooks Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register auth-github Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register auth-google Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register auth-ldap Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register auth-saml Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register netbox Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register test-plugin Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register transport-icinga2 Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register transport-nagios Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register transport-slack Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register transport-xmpp Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register web-hooks Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register usage-report Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register backup-reports Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.945Z xo:plugin INFO successfully register transport-email Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.956Z xo:plugin INFO successfully register audit Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.957Z xo:plugin INFO successfully register load-balancer Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.957Z xo:plugin INFO successfully register perf-alert Feb 10 17:59:07 tb-xoce-e-19 xo-server[837]: 2023-02-10T15:59:07.966Z xo:plugin INFO successfully register sdn-controller Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): taskRef: OpaqueRef:655531f1-ba0b-4583-95a2-f376bf85f526 Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): useHack: false Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): taskRef: OpaqueRef:1b623504-9dd2-4d4a-96a8-fca88adbb66e Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): useHack: false Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): taskRef: OpaqueRef:0323510a-df09-4072-8e43-c9a34449c396 Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): useHack: false Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): taskRef: OpaqueRef:72eed850-b1e3-438c-987e-469cd1331845 Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): useHack: false Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): waiting for request to finish Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): waiting for request to finish Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): waiting for request to finish Feb 10 17:59:37 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): waiting for request to finish Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): response#readable Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): request#close Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): request#unpipe Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): body#error Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): body#unpipe Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): body#close Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): waiting for response to finish Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): response#resume Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): response#end Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): response#close Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(3n9ugoikq5v): returning task result promise Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): body#prefinish Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): body#end Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): request#unpipe Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): request#prefinish Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): body#finish Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): body#unpipe Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): request#finish Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): body#close Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): waiting for response to finish Feb 10 17:59:38 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): response#resume Feb 10 17:59:39 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): response#readable Feb 10 17:59:39 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): response#end Feb 10 17:59:39 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): response#close Feb 10 17:59:39 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): returning task result promise Feb 10 17:59:39 tb-xoce-e-19 xo-server[1181]: putResource(rhnuq5h5ix): request#close Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): response#readable Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): request#close Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): request#unpipe Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): body#error Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): body#unpipe Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): body#close Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): waiting for response to finish Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): response#resume Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): response#end Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): response#close Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(q3eg2gp4h0m): returning task result promise Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): response#readable Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): request#close Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): request#unpipe Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): body#error Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): body#unpipe Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): body#close Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): waiting for response to finish Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): response#resume Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): response#end Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): response#close Feb 10 17:59:47 tb-xoce-e-19 xo-server[1181]: putResource(7x5rgk2ksq4): returning task result promise Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: [WARN] plugin transport-email: Error: No recipients defined Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._formatError (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:790:19) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._setEnvelope (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:1007:34) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection.send (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:621:14) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at sendMessage (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-transport/index.js:228:28) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at /opt/xen-orchestra/node_modules/nodemailer/lib/smtp-transport/index.js:289:21 Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection.<anonymous> (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:213:17) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Object.onceWrapper (node:events:627:28) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection.emit (node:events:513:28) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection.patchedEmit [as emit] (/opt/xen-orchestra/@xen-orchestra/log/configure.js:52:17) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._actionEHLO (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:1331:14) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._processResponse (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:953:20) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._onData (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:755:14) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Socket.SMTPConnection._onSocketData (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:193:44) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Socket.emit (node:events:513:28) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Socket.patchedEmit [as emit] (/opt/xen-orchestra/@xen-orchestra/log/configure.js:52:17) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at addChunk (node:internal/streams/readable:324:12) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at readableAddChunk (node:internal/streams/readable:297:9) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Socket.Readable.push (node:internal/streams/readable:234:10) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at TCP.onStreamRead (node:internal/stream_base_commons:190:23) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at TCP.callbackTrampoline (node:internal/async_hooks:130:17) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: 2023-02-10T16:00:23.194Z xo:xo-server WARN possibly unhandled rejection { Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: error: Error: No recipients defined Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._formatError (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:790:19) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._setEnvelope (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:1007:34) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection.send (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:621:14) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at sendMessage (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-transport/index.js:228:28) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at /opt/xen-orchestra/node_modules/nodemailer/lib/smtp-transport/index.js:289:21 Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection.<anonymous> (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:213:17) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Object.onceWrapper (node:events:627:28) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection.emit (node:events:513:28) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection.patchedEmit [as emit] (/opt/xen-orchestra/@xen-orchestra/log/configure.js:52:17) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._actionEHLO (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:1331:14) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._processResponse (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:953:20) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at SMTPConnection._onData (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:755:14) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Socket.SMTPConnection._onSocketData (/opt/xen-orchestra/node_modules/nodemailer/lib/smtp-connection/index.js:193:44) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Socket.emit (node:events:513:28) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Socket.patchedEmit [as emit] (/opt/xen-orchestra/@xen-orchestra/log/configure.js:52:17) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at addChunk (node:internal/streams/readable:324:12) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at readableAddChunk (node:internal/streams/readable:297:9) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at Socket.Readable.push (node:internal/streams/readable:234:10) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at TCP.onStreamRead (node:internal/stream_base_commons:190:23) Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: at TCP.callbackTrampoline (node:internal/async_hooks:130:17) { Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: code: 'EENVELOPE', Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: command: 'API' Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: } Feb 10 18:00:23 tb-xoce-e-19 xo-server[837]: } Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): taskRef: OpaqueRef:f3ef509e-4121-437b-b140-282419c869ba Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): taskRef: OpaqueRef:0b25fc40-83f1-44b3-86cf-59f00bbbc272 Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): taskRef: OpaqueRef:099a9a90-719d-4b5e-839a-7bdacfccf50d Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): taskRef: OpaqueRef:028adad2-d651-418d-b3bb-ca767daf3801 Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): taskRef: OpaqueRef:fd44c094-7dda-4a96-8ff4-2c76e4d75c80 Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): taskRef: OpaqueRef:4fe09fe7-63d7-4318-aa94-65362ce00cbd Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): taskRef: OpaqueRef:2b216564-d923-46b0-a377-08806e4d28a1 Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): taskRef: OpaqueRef:9ad749aa-baed-4ce1-8ded-27ee463bbd87 Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): taskRef: OpaqueRef:40ac30f8-240b-4278-93a1-5cb6b3d2e681 Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): taskRef: OpaqueRef:948bec59-35a8-41fb-849e-3c3c33214fc2 Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): useHack: false Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): waiting for request to finish Feb 10 18:00:30 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): waiting for request to finish Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): response#readable Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): request#close Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): request#unpipe Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): body#error Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): body#unpipe Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): body#close Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): waiting for response to finish Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): response#resume Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): response#end Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): response#close Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(ytgd25jz6wi): returning task result promise Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): body#prefinish Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): body#end Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): request#unpipe Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): request#prefinish Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): body#finish Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): body#unpipe Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): request#finish Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): body#close Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): waiting for response to finish Feb 10 18:00:32 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): response#resume Feb 10 18:00:33 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): response#readable Feb 10 18:00:33 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): response#end Feb 10 18:00:33 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): response#close Feb 10 18:00:33 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): returning task result promise Feb 10 18:00:33 tb-xoce-e-19 xo-server[1209]: putResource(eqjv69wmqff): request#close Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): response#readable Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): request#close Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): request#unpipe Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): body#error Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): body#unpipe Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): body#close Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): waiting for response to finish Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): response#resume Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): response#end Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): response#close Feb 10 18:07:19 tb-xoce-e-19 xo-server[1209]: putResource(n0ygkko6hs): returning task result promise Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): response#readable Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): request#close Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): request#unpipe Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): body#error Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): body#unpipe Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): body#close Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): waiting for response to finish Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): response#resume Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): response#end Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): response#close Feb 10 18:07:20 tb-xoce-e-19 xo-server[1209]: putResource(7dnih4mm1qf): returning task result promise Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): response#readable Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): request#close Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): request#unpipe Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): body#error Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): body#unpipe Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): body#close Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): waiting for response to finish Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): response#resume Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): response#end Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): response#close Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(v44nlq1wrs8): returning task result promise Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): response#readable Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): request#close Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): request#unpipe Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): body#error Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): body#unpipe Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): body#close Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): waiting for response to finish Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): response#resume Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): response#end Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): response#close Feb 10 18:09:05 tb-xoce-e-19 xo-server[1209]: putResource(uljxc697y2l): returning task result promise Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): response#readable Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): request#close Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): request#unpipe Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): body#error Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): body#unpipe Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): body#close Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): waiting for response to finish Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): response#resume Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): response#end Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): response#close Feb 10 18:28:03 tb-xoce-e-19 xo-server[1209]: putResource(zwad8yuqlz): returning task result promise Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): response#readable Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): request#close Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): request#unpipe Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): body#error Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): body#unpipe Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): body#close Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): waiting for response to finish Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): response#resume Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): response#end Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): response#close Feb 10 18:28:04 tb-xoce-e-19 xo-server[1209]: putResource(e9in7oo6sxp): returning task result promise Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): response#readable Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): request#close Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): request#unpipe Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): body#error Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): body#unpipe Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): body#close Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): waiting for response to finish Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): response#resume Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): response#end Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): response#close Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(30gsda5k9w): returning task result promise Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): response#readable Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): request#close Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): request#unpipe Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): body#error Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): body#unpipe Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): body#close Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): waiting for response to finish Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): response#resume Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): response#end Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): response#close Feb 10 18:28:55 tb-xoce-e-19 xo-server[1209]: putResource(oabtodmaeda): returning task result promise -
Thanks to you both, I have what I need to work on this for the moment, I'll keep you posted when I have something more to test
-
@julien-f Any new thoughts on this issue?
-
@Andrew Yes, I'm working on this and should have something to test tomorrow
-
@Andrew @Gheppy, I have something new test, it's an important change concerning a low-level component of XO, hopefully I did not break anything
The
cr-issuebranch has been rebased, make sure to reset it properly, re-install dependencies and rebuild:cd xen-orchestra/ git checkout cr-issue git fetch git reset --hard origin/cr-issue yarn yarn buildLet me know if you have any issues
-
@julien-f
I'll tested in a short time, I am in the middle of CR for next 6 hours -
@julien-f Broken. Job failed. Lots of
Error: Premature close. Data not replicated.Job report: job.txt (text format)
Journal XO output: out.txt.gz (GZ format).
-
-
I still don't understand exactly the issue, not sure if it comes from XO or XCP-ng/XenServer, but latest version does integrate a work-around, if you encounter Premature close error during CR, you can add the following to your xo-server's configuration file (usually
/etc/xo-server/config.toml) :[xapiOptions] ignorePrematureClose = trueIt's not enabled by default until completely understand the root cause and it's properly fixed.
@Gheppy Thanks a lot for your tests and feedbacks
@Andrew Thank you very much for the test appliance, it was an invaluable help investigating this. If you can keep it online for the time being I'll probably have further tests to do with it next week
-
@julien-f I updated XO Source to current master and added the new ignorePrematureClose=true option. Backup ran the CR correctly again.
Yes, I can leave the XOA test tunnel up for testing. I'm happy to help you help me!
-
@Andrew do you still have the issue without the
ignorePrematureClose? -
@olivierlambert Yes. Still problems on the new code without the option set. 90% of the VMs fail 10% finish correctly on CR.
-
Thanks for your precious feedback
-
Just for info
I installed the latest version of XOCE, commit 083db67df9e1645a2f8fe2fac564b3aecf30d55e
CR is ok and can be used in case of disaster, with ignorePrematureClose = true.
I managed to start the VM without problems, the VM itself ( that is the CR copy ) .
At the moment I have a very slow copy problem of the VM that is created with CR on the seccond server ( 18Mb max ), the problem is that the same connection goes with 400Mb for a CR copy. I want to make a copy of VM-CR and start it -
G Gheppy referenced this topic on
-
@Gheppy weird.. DR is now working for me but CR is still never ending
-
@magicker
You need to add this on config file.
Location for me is /opt/xen-orchestra/packages/xo-server/.xo-server.toml[xapiOptions] ignorePrematureClose = true -
@Gheppy Yes.. putting that in place seemed to fix DR.. but not CR.
