ova import failing silently. logs show timeout against xcp-ng node

ITJamie

@ITJamie Screenshot 2022-02-17 at 11.57.00.png

after messing around re-attempting uploads. i managed to get this to appear in debugger console logs...

ITJamie

@olivierlambert
firefox (latest after i upgraded it) on windows just worked!
managed to upload the ubuntu image and the watchguard image!

so nether firefox nor chrome worked on mac.
firefox (97.0) did work on windows.
firefox uploads worked to both local storage and nfs

chrome didnt work on windows when i tried yesterday. however today when i rdp'd in i noticed it was awaiting an upgrade. post upgrade it did manage to upload (im not sure how out of date it was, i dont use windows much)

so currently it means we can work with xoa uploader on windows. but not mac (at least, not m1x arm64 macs, ill try pull out one of my older macs later and see if it works on x86-64 bit mac)

if theres any additional tests you need me to perform to try help that other user @nraynaud mentioned id be happy to.

nraynaud

@ITJamie thanks! it's the first clue ever we get on this problem.

and it is front side, which makes it a bit easier to find.

It's not a slam dunk, because it works here, on a mac with chrome, mut we have a lead.

ITJamie

@nraynaud
if there is a way to quickly enable a lot of console logging for this im happy to swap out the xoa build and re-test and give you logs

nraynaud

@ITJamie oh I see you're building from sources, even better, would you mind being my eyes in Chrome debugger?

when you click on the 'import' button (maybe for a failing VMDK disk, it's the simplest code path that fails) there should be a POST request to a weird URL , if you could tell me the content-length of the request (not the response), and if you see anything untowards in the payload.

here is a capture of a normal thing on my computer:
https://gfycat.com/aggressivedisgustinggopher (there is an HD button at the bottom right)
the payload size should be a few KB and at the bottom there should be the file name. No private information transits here, it's the addresses of the the blocks in the file, not their content.

Thank you for your help.

nraynaud

@ITJamie No, we don't have any hierarchical log system on the front side AFAIK.

ITJamie

@nraynaud So this is interesting.
there is no payload at all, and it takes quite awhile for any of the tabs (including headers) to show any data.
the response and request section are completely empty.

heres the "copied as curl"

curl 'http://<ip>/api/xwE65b7EvmOp46LgogDxER7co_8Jl1P2NktYW_oszOs' -X POST -H 'User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:96.0) Gecko/20100101 Firefox/96.0' -H 'Accept: */*' -H 'Accept-Language: en-US,en;q=0.5' -H 'Accept-Encoding: gzip, deflate' -H 'Referer: http://<ip>/' -H 'Content-Type: multipart/form-data; boundary=---------------------------274750692132175193903430548728' -H 'Origin: http://<ip>' -H 'Content-Length: 960097718' -H 'Connection: keep-alive' -H 'Cookie: <removed>'

ITJamie

@nraynaud
I left the above running until now in firefox. it still had not showed any data in response or request.

Once i refreshed the page I got this console error
importVms watchguard-dimension_2_2.ova TypeError: NetworkError when attempting to fetch resource. index.js:172:159005

This would seem to me that the page had been waiting for something all that time

ITJamie

@nraynaud sadly ive started to see import errors again...

Ive tried changing builds on the xoa side but it doesnt seem to fix it...
previous ovf files that were working have not stopped importing.

example of the error on xcp-ng side

Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] Importing raw VDI R:d744d9fee162 failed with exception Server_error(VDI_IO_ERROR, [ Device I/O errors ])
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] Raised Server_error(VDI_IO_ERROR, [ Device I/O errors ])
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 1/12 xapi Raised at file ocaml/xapi/vhd_tool_wrapper.ml, line 75
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 2/12 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 3/12 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 35
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 4/12 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 5/12 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 35
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 6/12 xapi Called from file ocaml/xapi/import_raw_vdi.ml, line 156
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 7/12 xapi Called from file ocaml/xapi/import_raw_vdi.ml, line 194
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 8/12 xapi Called from file ocaml/xapi/server_helpers.ml, line 100
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 9/12 xapi Called from file ocaml/xapi/server_helpers.ml, line 121
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 10/12 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 11/12 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 35
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 12/12 xapi Called from file lib/backtrace.ml, line 177
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace]
Feb 24 15:08:32 xcp-ng-03958 xapi: [debug||1252 /var/lib/xcp/xapi||dummytaskhelper] task dispatch:session.logout D:aecf708cfad5 created by task D:6567b55f1ad9
Feb 24 15:08:32 xcp-ng-03958 xapi: [ info||1252 /var/lib/xcp/xapi|session.logout D:df9fcc048c68|xapi_session] Session.destroy trackid=ec26a660c6eeea965008c581e6547c0d
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||import] Caught exception in import handler: VDI_IO_ERROR: [ Device I/O errors ]
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] VDI.import D:6567b55f1ad9 failed with exception Unix.Unix_error(Unix.EPIPE, "single_write", "")
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] Raised Unix.Unix_error(Unix.EPIPE, "single_write", "")
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 1/9 xapi Raised at file unix.ml, line 328
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 2/9 xapi Called from file lib/xapi-stdext-unix/unixext.ml, line 469
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 3/9 xapi Called from file lib/xapi-stdext-unix/unixext.ml, line 471
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 4/9 xapi Called from file ocaml/xapi/import_raw_vdi.ml, line 232
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 5/9 xapi Called from file ocaml/xapi/server_helpers.ml, line 100
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 6/9 xapi Called from file ocaml/xapi/server_helpers.ml, line 121
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 7/9 xapi Called from file lib/xapi-stdext-pervasives/pervasiveext.ml, line 24
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 8/9 xapi Called from file map.ml, line 135
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 9/9 xapi Called from file sexp_conv.ml, line 147
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace]
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] VDI.import D:957854cadc4e failed with exception Unix.Unix_error(Unix.EPIPE, "single_write", "")
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] Raised Unix.Unix_error(Unix.EPIPE, "single_write", "")
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace] 1/1 xapi Raised at file (Thread 1158 has no backtrace table. Was with_backtraces called?, line 0
Feb 24 15:08:32 xcp-ng-03958 xapi: [error||1158 :::80||backtrace]
Feb 24 15:08:32 xcp-ng-03958 xapi: [debug||149 ||xenops] Event on VM 12558119-28e5-4a64-9053-1c0074c5b641; resident_here = true
Feb 24 15:08:32 xcp-ng-03958 xapi: [debug||149 ||dummytaskhelper] task timeboxed_rpc D:168d1d548a5c created by task D:a90e0cbb13bb

i also installed the official appliance on another ip. that worked correctly for loading the same ova files...

I did notice that the official ova image mentions node 14 during its upgrade process. I built from sources with node 17 since the xoa docs say to use latest. Think this issue could be down to using a much newer node version?

nraynaud

@ITJamie I'm sorry I can't answer about the node version until we get the bug.

I suspect there is some kind of compounding, where an error happens somewhere, but is lost by improper error handling, and no all we see is a corrupted state long after the error happened.

Arraylist

@ITJamie I am having the same issue!
Same error, also trying to import Watchguard Dimension 2.2.
I am on XOA 5.67 (node: 16.13.2) and XCP-ng 8.2.1.
I am using Windows and tried with Firefox 97 and Chrome 98, fails with both.
The VM also kind of gets created (with the [Importing] before the name, which never goes away).
Both disks also get created (Data disk looks complete, but System disk is always attached to control domain on host)

olivierlambert

@Arraylist can you switch to latest branch of your XOA please? We'll see if this has any impact

Arraylist

@olivierlambert just upgraded to 5.68, issue is still here.

olivierlambert

Anything is the console browser? Do you know if any transfer actually started between your browser and the host?

ITJamie

Ive done a fresh install on debian 11 with node 14.18.3
It now works! from windows and mac. ova's and disk imports

Arraylist

@olivierlambert Yes, I can see network troughput from my client to XOA and from XOA to the XCP-ng host:

olivierlambert

That's interesting

@Arraylist would you be able to install XO from the sources with Node 14 and report if it works on your side?

Arraylist

@olivierlambert just did a fresh install of debian 11 with node 14.18.3
Fails. Error is the same.

olivierlambert

That's weird that we got different behaviour with the very same code To me, there's something else causing a problem.

yannik

Hi,

first of all, thank you for developing and supporting these awesome products.

I witnessed a similar issue upon running continuous replication on a VM after growing one of the disks on the source side. I run delta backup to a NFS share and continuous replication to another XCP-ng host in one job.

The most important part of the relevant log messages remind me of this issue - this topic is the only similar reference I was able to find, so I hope this is the right place to post. If not, please let me know, and I'll create a new topic

Mar 21 01:00:29 xcp-ng-2 xapi: [ info||8947241 INET :::80|Importing raw VDI R:3967654dad6b|vhd_tool_wrapper] Executing /bin/vhd-tool serve --source-format vhd --source-protocol none --source-fd 1f47b1fe-a9ea-4bda-ab8e-2101e5677059 --tar-filename-prefix  --destination file:///dev/sm/backend/f7aca870-12e0-8352-9f86-f52d575eb313/6cd16448-6839-476d-93b1-2f8b816c827f --destination-format raw --progress --machine --direct --destination-size 0 --prezeroed
Mar 21 01:00:29 xcp-ng-2 xapi: [error||8947241 INET :::80|Importing raw VDI R:3967654dad6b|vhd_tool_wrapper] vhd-tool failed, returning VDI_IO_ERROR
Mar 21 01:00:29 xcp-ng-2 xapi: [error||8947241 INET :::80|Importing raw VDI R:3967654dad6b|vhd_tool_wrapper] vhd-tool output: vhd-tool: Non-zero size required (either a pre-existing destination file or specified via --destination-size on the command line)\x0A

I'm currently running Xen Orchestra compiled from sources, on commit 5bc44363f9ac9fa534f3247e697f1b3c6991e916. XCP-ng is on version 8.2.0.
I know that this is not fully up-to-date, but after retrying that backup as a first measure, Xen Orchestra ran a full backup for that VM, so I can't reproduce that issue anymore, but I figured posting that here might help resolving the aforementioned issue, if the causes correlate.