vmware / govmomi

Go library for the VMware vSphere API
Apache License 2.0
2.33k stars 912 forks source link

[BUG] govmomi/guest/toolbox.Download() returning `stream error: failing with stream ID 1; NO_ERROR; received from peer` #3635

Open mjb2k opened 20 hours ago

mjb2k commented 20 hours ago

Describe the bug Sometimes, after some amount of uses, the toolbox.Download() endpoint is returning this error: stream error: failing with stream ID 1; NO_ERROR; received from peer. This happens after about 50 seconds of trying to load the file. I also can verify it's not a network issue with my computer and the VM as they are on the same network.

My hunch is this might be an error with VMWare Tools, but I'd figure I'd ask here since it was caused when I used the govmomi library, and at the very least might be able to add some useful documentation for this error to the Github.

To Reproduce Steps to reproduce the behavior:

  1. Create Toolbox session with VM
  2. Run `toolbox.Client.Download(ctx, src)

Expected behavior An io.ReadCloser return type

Affected version v0.37.3

Screenshots/Debug Output I also have a log of host.d of ESXi in addition to the error passed by the toolbox method.

2024-12-04T21:35:05.487Z In(166) Hostd[2098866]: [Originator@6876 sub=Guestsvc.GuestFileTransfer] StoreAndReturnToken: Generated token: 52fefac9-6c16-2478-4794-b7c340110cd11357
2024-12-04T21:35:05.488Z Db(167) Hostd[2098866]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Initiate file transfer from guest translated error to success
2024-12-04T21:35:05.488Z In(166) Hostd[2098900]: [Originator@6876 sub=Vimsvc.ha-eventmgr] Event 73312 : Guest operation Initiate File Transfer From Guest performed on Virtual machine python-windows-10-ssd.
2024-12-04T21:35:05.489Z In(166) Hostd[2098900]: [Originator@6876 sub=Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] State Transition (VM_STATE_GUEST_OPERATION -> VM_STATE_ON)
2024-12-04T21:35:05.491Z In(166) Hostd[2098867]: [Originator@6876 sub=Hbrsvc] Replicator: powerstate change VM: 1357 Old: 1 New: 1
2024-12-04T21:35:05.503Z In(166) Hostd[2098898]: [Originator@6876 sub=Guestsvc.GuestFileHandler] GetGuestFileTransferParameters, token is 52fefac9-6c16-2478-4794-b7c340110cd11357
2024-12-04T21:35:05.503Z In(166) Hostd[2098898]: [Originator@6876 sub=Guestsvc.GuestFileHandler] GetGuestFileTransferParameters: vmmoid is 1357
2024-12-04T21:35:05.503Z In(166) Hostd[2098898]: [Originator@6876 sub=Guestsvc.GuestFileHandler] Guest File Path is C:\Users\edrsilencer\get_ui_elements.json
2024-12-04T21:35:05.587Z Db(167) Hostd[2098893]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:05.587Z In(166) Hostd[2098896]: [Originator@6876 sub=Libs] HGFileCopyCreateSessionCB: Successfully created the session.
2024-12-04T21:35:05.635Z Db(167) Hostd[2098894]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:05.731Z Db(167) Hostd[2098894]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:05.828Z Db(167) Hostd[2098879]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:05.925Z Db(167) Hostd[2098878]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:05.972Z Db(167) Hostd[2098887]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.052Z Db(167) Hostd[2098884]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.148Z Db(167) Hostd[2098868]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.197Z Db(167) Hostd[2098874]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.276Z Db(167) Hostd[2098866]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.325Z Db(167) Hostd[2098883]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.372Z Db(167) Hostd[2098868]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.421Z Db(167) Hostd[2098878]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.499Z Db(167) Hostd[2098899]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.547Z Db(167) Hostd[2098888]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:06.595Z Db(167) Hostd[2098889]: [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/67408e59-ec6f2742-d9aa-3cecef1f15c8/python-windows-10-ssd/python-windows-10-ssd.vmx] Copy file send packet translated error to success
2024-12-04T21:35:11.192Z In(166) Hostd[2098894]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa0834168, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 15269'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa0834168, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 15269'>>, duration: 00:00:47.964199 (hh:mm:ss.us))
2024-12-04T21:35:11.193Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:11.193Z In(166) Hostd[2098871]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa06b4d08, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa06b4d08, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, duration: 00:00:46.675947 (hh:mm:ss.us))
2024-12-04T21:35:11.194Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:11.192Z In(166) Hostd[2098872]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005a9c282b08, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005a9c282b08, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, duration: 00:00:46.685835 (hh:mm:ss.us))
2024-12-04T21:35:11.196Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:11.193Z In(166) Hostd[2098873]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa07f24e8, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa07f24e8, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, duration: 00:00:46.675637 (hh:mm:ss.us))
2024-12-04T21:35:11.197Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:11.192Z In(166) Hostd[2098866]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa01fdca8, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa01fdca8, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, duration: 00:00:46.686267 (hh:mm:ss.us))
2024-12-04T21:35:11.199Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:11.193Z In(166) Hostd[2098876]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa0813198, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 36622'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa0813198, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 36622'>>, duration: 00:00:46.676113 (hh:mm:ss.us))
2024-12-04T21:35:11.201Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:11.212Z In(166) Hostd[2098868]: [Originator@6876 sub=Solo.HTTP server /host user=root] Sent OK response for GET /host/hostd.log
2024-12-04T21:35:16.196Z In(166) Hostd[2098866]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa0b161d8, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa0b161d8, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, duration: 00:00:48.085773 (hh:mm:ss.us))
2024-12-04T21:35:16.197Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:16.196Z In(166) Hostd[2098891]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005a9c677818, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005a9c677818, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, duration: 00:00:48.086225 (hh:mm:ss.us))
2024-12-04T21:35:16.198Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:16.196Z In(166) Hostd[2098889]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005a47e6a608, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 45916'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005a47e6a608, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 45916'>>, duration: 00:00:48.086330 (hh:mm:ss.us))
2024-12-04T21:35:16.200Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:16.196Z In(166) Hostd[2098883]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa0a31308, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 50360'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa0a31308, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 50360'>>, duration: 00:00:48.085898 (hh:mm:ss.us))
2024-12-04T21:35:16.201Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:16.196Z In(166) Hostd[2098875]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa0a5a698, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 52698'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa0a5a698, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '127.0.0.1 : 52698'>>, duration: 00:00:45.704481 (hh:mm:ss.us))
2024-12-04T21:35:16.203Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:26.202Z In(166) Hostd[2098898]: [Originator@6876 sub=SoapAdapter.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa084e6d8, h:-1, <TCP '127.0.0.1 : 8307'>, <TCP '127.0.0.1 : 58272'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa084e6d8, h:-1, <TCP '127.0.0.1 : 8307'>, <TCP '127.0.0.1 : 58272'>>, duration: 00:00:48.278362 (hh:mm:ss.us))
2024-12-04T21:35:26.203Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
2024-12-04T21:35:31.205Z In(166) Hostd[2098883]: [Originator@6876 sub=Solo.HttpSvc.HTTPService.HttpConnection] HTTP Connection read failed while waiting for further requests; <io_obj p:0x0000005aa04f1d28, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, N7Vmacore16TimeoutExceptionE(Operation timed out: Stream: <io_obj p:0x0000005aa04f1d28, h:-1, <TCP '127.0.0.1 : 8309'>, <TCP '0.0.0.0 : 0'>>, duration: 00:00:46.514746 (hh:mm:ss.us))
2024-12-04T21:35:31.207Z In(166) Hostd[2098844]: --> [context]zKq7AVICAgAAAP////8JaG9zdGQAAANZQWxpYnZtYWNvcmUuc28AAI4PNwCieicA0HsnAI4xKACwTCgAS9lJAYJ6AGxpYnB0aHJlYWQuc28uMAAC7y4PbGliYy5zby42AA==[/context]
github-actions[bot] commented 20 hours ago

Howdy 🖐   mjb2k ! Thank you for your interest in this project. We value your feedback and will respond soon.

If you want to contribute to this project, please make yourself familiar with the CONTRIBUTION guidelines.