Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

x/net/http2: stream was reset: PROTOCOL_ERROR #31534

Open
sinhaashish opened this issue Apr 18, 2019 · 12 comments
Open

x/net/http2: stream was reset: PROTOCOL_ERROR #31534

sinhaashish opened this issue Apr 18, 2019 · 12 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@sinhaashish
Copy link

What version of Go are you using (go version)?

$ go version
go version go1.12 linux/amd64

Does this issue reproduce with the latest release?

What operating system and processor architecture are you using (go env)?

go env Output
$ go env

GOARCH="amd64"
GOBIN=""
GOCACHE="/home/ashish/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/ashish/code/go"
GOPROXY=""
GORACE=""
GOROOT="/home/ashish/.gimme/versions/go1.12.linux.amd64"
GOTMPDIR=""
GOTOOLDIR="/home/ashish/.gimme/versions/go1.12.linux.amd64/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/ashish/code/go/src/github.com/minio/minio-java/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build786486078=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I am using minio for Object storage. Minio is a golang project using go1.12 as the base go version.
The server is HTTP2 enabled. I use using minio java client which uses okhttp3 . when i try to store the object in a bucket in multi threaded mode i get okhttp3.internal.http2.StreamResetException: stream was reset: NO_ERROR.
Refer minio/minio#7501 .

okhttp3.OkHttpClient uses http2.0 by default which causes such issue.
If i forcefuly set the protocol to 1.1 ,it works fine.
Refer PR minio/minio-java#766.

I find there is some issue with Go1.12 or okhttp3 as i found this issue in the community.
Refer square/okhttp#3955
The only solution provided there was to revert to HTTP1_1 .

Setting the protocol to 1.1 is not the solution as i am not using the functionality of HTTP2.0 enabled server.

Raised the issue with okhhttp refer square/okhttp#4964
Below is the code which replicates the problem

import io.minio.MinioClient;
class PutObjectRunnable implements Runnable {
   MinioClient client;
   String bucketName;
   String filename;

   public PutObjectRunnable(MinioClient client, String bucketName, String filename) {
       this.client = client;
       this.bucketName = bucketName;
       this.filename = filename;
   }

   public void run() {
       StringBuffer traceBuffer = new StringBuffer();

       try {

           client.putObject(bucketName, filename, filename);

       } catch (Exception e) {
           System.err.print(traceBuffer.toString());
           e.printStackTrace();
       }
   }
}



public class ThreadedPutObject {
    public static void main(String args[]) throws Exception {
	try{
        MinioClient client = new MinioClient("https://play.min.io:9000", "Q3AM3UQ867SPQQA43P2F", "zuf+tfteSlswRu7BJ86wekitnifILbZam1KYY3TG", true);
        client.traceOn(System.out);
        long startTime = System.currentTimeMillis();
		 boolean found = minioClient.bucketExists("my-bucketname");
      if (found) {
        System.out.println("my-bucketname already exists");
      } else {
        // Create bucket 'my-bucketname'.
        minioClient.makeBucket("my-bucketname");
        System.out.println("my-bucketname is created successfully");
      }        
      Thread[] threads = new Thread[7];
      String[] location = new String[]{"<<PATH_TO_OBJECT_1>>",
                                       "<<PATH_TO_OBJECT_2>>",
                                       "<<PATH_TO_OBJECT_3>>",
                                       "<<PATH_TO_OBJECT_4>>",
                                       "<<PATH_TO_OBJECT_5>>",
                                       "<<PATH_TO_OBJECT_6>>",	
                                       "<<PATH_TO_OBJECT_7>>" };

      for (int i = 0; i < 7; i++) {
            PutObjectRunnable pr = new PutObjectRunnable(client, "my-bucketname",location[i] );
          threads[i] = new Thread(pr);
      }
      for (int i = 0; i < 7; i++) {
        threads[i].start();
      }
            // Waiting for threads to complete.
      for (int i = 0; i < 7; i++) {
         threads[i].join();
          System.out.println(i);
        }
        // All threads are completed.
        } catch (Exception e) {
            throw e;
        }
        System.out.println("uploaded");
    }
}

What did you expect to see?

Object should have been uploaded.

What did you see instead?

okhttp3.internal.http2.StreamResetException: stream was reset: PROTOCOL_ERROR
@agnivade
Copy link
Contributor

Can you run the Minio server with GODEBUG=http2debug=2 and paste the logs ?

@sinhaashish sinhaashish mentioned this issue Apr 19, 2019
Closed
@sinhaashish
Copy link
Author

GODEBUG=http2debug=2

Log :

2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:54 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=b335653e30400fb6db22eb75e23fde1378f05eef08218bee66bcce558a9b4fc2"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:54 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:54 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36965 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:54 http2: server read frame HEADERS flags=END_HEADERS stream=36967 len=39
2019/04/19 21:23:54 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36969 len=39
2019/04/19 21:23:54 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:54 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty"
2019/04/19 21:23:54 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:54 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:54 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:54 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=b335653e30400fb6db22eb75e23fde1378f05eef08218bee66bcce558a9b4fc2"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:54 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:54 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36967 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:54 http2: server read frame HEADERS flags=END_HEADERS stream=36969 len=39
2019/04/19 21:23:54 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36971 len=41
2019/04/19 21:23:54 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:54 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_2"
2019/04/19 21:23:54 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:54 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:54 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:54 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=abafdaf947e7687ca64eb6cba6789b06a3e5dfa0ee4e46c6de5fbcf87bb55668"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:54 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:54 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36969 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:54 http2: server read frame HEADERS flags=END_HEADERS stream=36971 len=41
2019/04/19 21:23:54 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36973 len=41
2019/04/19 21:23:54 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:54 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_2"
2019/04/19 21:23:54 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:54 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:54 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:54 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=abafdaf947e7687ca64eb6cba6789b06a3e5dfa0ee4e46c6de5fbcf87bb55668"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:54 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:54 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36971 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:54 http2: server read frame HEADERS flags=END_HEADERS stream=36973 len=41
2019/04/19 21:23:54 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36975 len=41
2019/04/19 21:23:54 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:54 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_1"
2019/04/19 21:23:54 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:54 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:54 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:54 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=16f11d231a3e2c989cd1dcfad7b34b4c53411b091b8535a877ddc18f80d36268"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:54 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:54 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36973 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:54 http2: server read frame HEADERS flags=END_HEADERS stream=36975 len=41
2019/04/19 21:23:54 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36977 len=39
2019/04/19 21:23:54 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:54 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty"
2019/04/19 21:23:54 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:54 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:54 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:54 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:54 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=b335653e30400fb6db22eb75e23fde1378f05eef08218bee66bcce558a9b4fc2"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:54 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36977 len=39
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36979 len=41
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_2"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=abafdaf947e7687ca64eb6cba6789b06a3e5dfa0ee4e46c6de5fbcf87bb55668"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36977 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36975 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36979 len=41
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36981 len=39
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=b335653e30400fb6db22eb75e23fde1378f05eef08218bee66bcce558a9b4fc2"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36979 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36981 len=39
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36983 len=41
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_1"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=16f11d231a3e2c989cd1dcfad7b34b4c53411b091b8535a877ddc18f80d36268"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36983 len=41
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36985 len=41
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_2"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=abafdaf947e7687ca64eb6cba6789b06a3e5dfa0ee4e46c6de5fbcf87bb55668"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36981 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36983 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36985 len=41
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36987 len=39
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=b335653e30400fb6db22eb75e23fde1378f05eef08218bee66bcce558a9b4fc2"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36985 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36987 len=39
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36989 len=41
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_1"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=16f11d231a3e2c989cd1dcfad7b34b4c53411b091b8535a877ddc18f80d36268"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36987 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36989 len=41
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36991 len=39
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=b335653e30400fb6db22eb75e23fde1378f05eef08218bee66bcce558a9b4fc2"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36989 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36991 len=39
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36993 len=41
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_2"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=abafdaf947e7687ca64eb6cba6789b06a3e5dfa0ee4e46c6de5fbcf87bb55668"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36991 len=4 ErrCode=PROTOCOL_ERROR
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36993 len=41
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36995 len=41
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty_1"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-md5" = "0ObLjpgreGc9ZUcDuWdW3g=="
2019/04/19 21:23:55 http2: decoded hpack field header field "user-agent" = "MinIO (amd64; amd64) minio-java/dev"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-content-sha256" = "UNSIGNED-PAYLOAD"
2019/04/19 21:23:55 http2: decoded hpack field header field "x-amz-date" = "20190419T155331Z"
2019/04/19 21:23:55 http2: decoded hpack field header field "authorization" = "AWS4-HMAC-SHA256 Credential=minio/20190419/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=16f11d231a3e2c989cd1dcfad7b34b4c53411b091b8535a877ddc18f80d36268"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-type" = "application/octet-stream"
2019/04/19 21:23:55 http2: decoded hpack field header field "content-length" = "308"
2019/04/19 21:23:55 http2: decoded hpack field header field "accept-encoding" = "gzip"
2019/04/19 21:23:55 http2: Framer 0xc00050e620: wrote RST_STREAM stream=36993 len=4 ErrCode=PROTOCOL_ERROR

API: SYSTEM()
Time: 21:23:55 IST 04/19/2019
Error: timed out. some connections are still active. doing abnormal shutdown
       1: cmd/signals.go:53:cmd.handleSignals.func2()
       2: cmd/signals.go:79:cmd.handleSignals()
       3: cmd/server-main.go:380:cmd.serverMain()
2019/04/19 21:23:55 http2: server read frame HEADERS flags=END_HEADERS stream=36995 len=41
2019/04/19 21:23:55 http2: Framer 0xc00050e620: read HEADERS flags=END_HEADERS stream=36997 len=39
2019/04/19 21:23:55 http2: decoded hpack field header field ":method" = "PUT"
2019/04/19 21:23:55 http2: decoded hpack field header field ":path" = "/sinha/home/ashish/Sample/empty"
2019/04/19 21:23:55 http2: decoded hpack field header field ":authority" = "localhost:9000"
2019/04/19 21:23:55 http2: decoded hpack field header field ":scheme" = "https"

@agnivade
Copy link
Contributor

@bradfitz @fraenkel

@fraenkel
Copy link
Contributor

@sinhaashish Next time please give us exact steps to reproduce the issue. The code above is incomplete and knowing to use the 6.0.5 version was not very obvious.
In the end, my version works just fine. I uploaded 7 files, 2 were the minio java client jars, 4 were the source and class files, and then a dummy file.

@sinhaashish
Copy link
Author

@sinhaashish Next time please give us exact steps to reproduce the issue. The code above is incomplete and knowing to use the 6.0.5 version was not very obvious.
In the end, my version works just fine. I uploaded 7 files, 2 were the minio java client jars, 4 were the source and class files, and then a dummy file.

@fraenkel : Can you try it a multiple of times, as the issue is sporadic for me too.

@fraenkel
Copy link
Contributor

@sinhaashish I have reproduced the issue. I am still determining the root cause. There are multiple issues going on here which is why it will take some time.

I see cases where the client side is reusing a closed stream and the server eventually says to GOAWAY.
After that point, it becomes a constant barage of PROTOCOL_ERROR which then subsides. New connections are created until we hit another issue which is exceeded the number of concurrent streams.
This is when the server side goes into a hard loop.

I will let you know more as I dig deeper.

@agnivade agnivade changed the title stream was reset: PROTOCOL_ERROR x/net/http2: stream was reset: PROTOCOL_ERROR Apr 20, 2019
@agnivade agnivade added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Apr 20, 2019
@agnivade agnivade added this to the Go1.13 milestone Apr 20, 2019
@fraenkel
Copy link
Contributor

Working backwards, the crazy looping looks like a minio issue which I have no plans to debug. The call stack is about 45 calls deep and the majority is minio and gorilla. Most of the threads are stuck waiting to read data from the body. This is when the number of concurrent requests is exceeded.

Other times, I see minio also stuck trying to grab locks during PutObject. This too is not something I will debug.

The only remaining investigation is the very first issue that occurs.

@fraenkel
Copy link
Contributor

The very first error that occurs looks like a client initiated issue.

2019/04/20 14:31:10 http2: framer 0xc0004441c0: wrote data stream=11 len=267 data="<?xml version=\"1.0\" encoding=\"utf-8\"?>\n<initiatemultipartuploadresult xmlns=\"http://s3.amazonaws.com/doc/2006-03-01/\"><bucket>my-bucketname</bucket><key>minio-6.0.6-all.jar</key><uploadid>af74c215-472d-4628-b1e6-09cb8c20f32b</uploadid></initiatemultipartup" (11 bytes omitted)
2019/04/20 14:31:10 http2: Framer 0xc0004441c0: wrote DATA flags=END_STREAM stream=11 len=0 data=""
2019/04/20 14:31:10 http2: Framer 0xc0004441c0: read GOAWAY len=8 LastStreamID=0 ErrCode=PROTOCOL_ERROR Debug=""

After the new connection is established, we then run into the issues listed above.

So far I don't see anything that points to an issue on the server side. Someone needs to investigate the client issue first.

@sinhaashish sinhaashish mentioned this issue Apr 22, 2019
Merged
@harshavardhana
Copy link
Contributor

What does it mean by client initiated issue ? Are you saying okhttp is buggy here ?

@fraenkel
Copy link
Contributor

I can only tell you what I see. Someone would have to debug the client side to see what is going on.

@sinhaashish sinhaashish mentioned this issue Apr 24, 2019
Closed
@harshavardhana
Copy link
Contributor

I can only tell you what I see. Someone would have to debug the client side to see what is going on.

Can you tell me exactly what that might be? - @fraenkel would like to share this with okhttp project?

@harshavardhana
Copy link
Contributor

Working backwards, the crazy looping looks like a minio issue which I have no plans to debug. The call stack is about 45 calls deep and the majority is minio and gorilla. Most of the threads are stuck waiting to read data from the body. This is when the number of concurrent requests is exceeded.

Other times, I see minio also stuck trying to grab locks during PutObject. This too is not something I will debug.

@fraenkel in this scenario the cause is HTTP 2.0 failing with HTTP 1.1 we don't see these issues at all. NOTE: nodes are also communicating over HTTP 2.0 with TLS connections as well as clients.

@harshavardhana harshavardhana mentioned this issue May 6, 2019
Closed
@andybons andybons modified the milestones: Go1.13, Go1.14 Jul 8, 2019
@rsc rsc modified the milestones: Go1.14, Backlog Oct 9, 2019
@bcmills bcmills mentioned this issue Feb 3, 2023
Open
@kgilonne kgilonne mentioned this issue Apr 19, 2023
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Milestone
Backlog
Development

No branches or pull requests
6 participants
@rsc @andybons @harshavardhana @fraenkel @agnivade @sinhaashish