Bug 1725730

Summary:	CDI: upload failure with Invalid JSON error after image validation (1 of 6 concurrent uploads)
Product:	Container Native Virtualization (CNV)	Reporter:	Natalie Gavrielov <ngavrilo>
Component:	Storage	Assignee:	Alexander Wels <awels>
Status:	CLOSED ERRATA	QA Contact:	Natalie Gavrielov <ngavrilo>
Severity:	medium	Docs Contact:
Priority:	high
Version:	2.0	CC:	alitke, cnv-qe-bugs, sgordon, ycui
Target Milestone:	---
Target Release:	2.1.0
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	CDI-2.1.0-12 HCO-2.1.0-29	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2019-10-31 14:08:47 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	1683163, 1705080

Description Natalie Gavrielov 2019-07-01 11:00:10 UTC

Description of problem:
one of 6 concurrent uploads failed with error:
unexpected end of JSON input
Invalid json for image /scratch/tmpimage

Version-Release number of selected component:
hco v2.0.0-30

How reproducible:
I only saw it once (and was unable to reproduce).

Steps to Reproduce:
In a cluster that has 12 pvs (6*25Gi, 6*10Gi) with 3 masters and 3 workers.
Try to upload 6 data volumes
1. Create 6 data volumes
2. Create 6 tokens
3. Wait for all pods to be running
4. start upload 

Actual results:
5 out of 6 uploads were successful, one pod is left with status Error.

Expected results:
All uploads to succeed.

Additional info:
From upload pod log:
I0630 14:35:55.676426       1 data-processor.go:173] Validating image
E0630 14:35:55.691042       1 qemu.go:156] Invalid JSON:

E0630 14:35:55.706343       1 data-processor.go:164] unexpected end of JSON input
Invalid json for image /scratch/tmpimage
kubevirt.io/containerized-data-importer/pkg/image.(*qemuOperations).Info
	/go/src/kubevirt.io/containerized-data-importer/pkg/image/qemu.go:157
kubevirt.io/containerized-data-importer/pkg/image.(*qemuOperations).Validate
	/go/src/kubevirt.io/containerized-data-importer/pkg/image/qemu.go:172
kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).validate
	/go/src/kubevirt.io/containerized-data-importer/pkg/importer/data-processor.go:174
kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).convert
	/go/src/kubevirt.io/containerized-data-importer/pkg/importer/data-processor.go:183
kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData
	/go/src/kubevirt.io/containerized-data-importer/pkg/importer/data-processor.go:157
kubevirt.io/containerized-data-importer/pkg/uploadserver.newUploadStreamProcessor
	/go/src/kubevirt.io/containerized-data-importer/pkg/uploadserver/uploadserver.go:260
kubevirt.io/containerized-data-importer/pkg/uploadserver.(*uploadServerApp).uploadHandler
	/go/src/kubevirt.io/containerized-data-importer/pkg/uploadserver/uploadserver.go:237
kubevirt.io/containerized-data-importer/pkg/uploadserver.(*uploadServerApp).uploadHandler-fm
	/go/src/kubevirt.io/containerized-data-importer/pkg/uploadserver/uploadserver.go:94
net/http.HandlerFunc.ServeHTTP
	/usr/lib/golang/src/net/http/server.go:1964
net/http.(*ServeMux).ServeHTTP
	/usr/lib/golang/src/net/http/server.go:2361
kubevirt.io/containerized-data-importer/pkg/uploadserver.(*uploadServerApp).ServeHTTP
	/go/src/kubevirt.io/containerized-data-importer/pkg/uploadserver/uploadserver.go:201
net/http.serverHandler.ServeHTTP
	/usr/lib/golang/src/net/http/server.go:2741
net/http.(*conn).serve
	/usr/lib/golang/src/net/http/server.go:1847
runtime.goexit
	/usr/lib/golang/src/runtime/asm_amd64.s:1333
Image validation failed
kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).validate
	/go/src/kubevirt.io/containerized-data-importer/pkg/importer/data-processor.go:176
kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).convert
	/go/src/kubevirt.io/containerized-data-importer/pkg/importer/data-processor.go:183
kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData
	/go/src/kubevirt.io/containerized-data-importer/pkg/importer/data-processor.go:157
kubevirt.io/containerized-data-importer/pkg/uploadserver.newUploadStreamProcessor
	/go/src/kubevirt.io/containerized-data-importer/pkg/uploadserver/uploadserver.go:260
kubevirt.io/containerized-data-importer/pkg/uploadserver.(*uploadServerApp).uploadHandler
	/go/src/kubevirt.io/containerized-data-importer/pkg/uploadserver/uploadserver.go:237
kubevirt.io/containerized-data-importer/pkg/uploadserver.(*uploadServerApp).uploadHandler-fm
	/go/src/kubevirt.io/containerized-data-importer/pkg/uploadserver/uploadserver.go:94
net/http.HandlerFunc.ServeHTTP
	/usr/lib/golang/src/net/http/server.go:1964
net/http.(*ServeMux).ServeHTTP
	/usr/lib/golang/src/net/http/server.go:2361
kubevirt.io/containerized-data-importer/pkg/uploadserver.(*uploadServerApp).ServeHTTP
	/go/src/kubevirt.io/containerized-data-importer/pkg/uploadserver/uploadserver.go:201
net/http.serverHandler.ServeHTTP
	/usr/lib/golang/src/net/http/server.go:2741
net/http.(*conn).serve
	/usr/lib/golang/src/net/http/server.go:1847
runtime.goexit
	/usr/lib/golang/src/runtime/asm_amd64.s:1333
I0630 14:35:55.706595       1 util.go:37] deleting file: /scratch/tmpimage
E0630 14:35:55.707612       1 uploadserver.go:243] Saving stream failed: Image validation failed: Invalid json for image /scratch/tmpimage: unexpected end of JSON input
error: unexpected EOF

Comment 1 Adam Litke 2019-08-21 14:25:30 UTC

*** Bug 1707418 has been marked as a duplicate of this bug. ***

Comment 2 Alexander Wels 2019-08-21 19:25:45 UTC

I was able to reproduce fairly consistently following the 6 concurrent uploads described here. Turns out there was a race between the stdout/err readers, and the cmd.Wait. Sometimes cmd.Wait could finish and close the streams before the readers had a chance to read. Posted PR to fix.

Comment 3 Natalie Gavrielov 2019-10-07 09:23:31 UTC

Verified, CDI v2.1.0-21.

Comment 5 errata-xmlrpc 2019-10-31 14:08:47 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2019:3282