Azure-sdk-for-js: @azure/storage-blob@>12.2.0 throws `Bad Request - Invalid Verb` on upload

Created on 11 Sep 2020  Â·  34Comments  Â·  Source: Azure/azure-sdk-for-js

Similar to #11163.

I have script running every 5 minutes for all of eternity that uploads to blob storage, starting ~a day ago I started getting consistent Bad Request - Invalid Verb errors from this code:

    const blobServiceClient = BlobServiceClient.fromConnectionString(key)
    const containerClient = blobServiceClient.getContainerClient(container)

    const createContainerResponse = containerClient.getBlockBlobClient(name)

    await createContainerResponse.uploadStream(Readable.from([text]))

This is consistent with the release of 12.2.0, which I see made some changes to the uploadStream method.

The exact response is as follows:

<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Bad Request</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Bad Request - Invalid Verb</h2>
<hr><p>HTTP Error 400. The request verb is invalid.</p>
</BODY></HTML> 
Client Storage bug customer-reported needs-team-attention

Most helpful comment

We belive this issue is addressed in the hotfix: @azure/[email protected] and @azure/[email protected]
Let me know if not.

All 34 comments

Oops, I thought it was something wrong with our live tests pipeline.
Does the error happen consistently for you or intermittently? I failed to find a way to recreate it locally 😢
Are you on Mac OS?

If you can recreate it easily, could you turn on the log and share me the logs specially the requestId via

import { setLogLevel } from "@azure/logger";
setLogLevel("info");

No worry if you can't recreate it. I will look into it.

I still can't recreate it even with the live tests pipeline now with https://github.com/Azure/azure-sdk-for-js/pull/11195. And the change for uploadStream in REST API level is only switching from upload(Buffer) to upload(()=>Readable). Don't see how this could cause the regression.
@jeremymeng Any idea?

@JacksonKearl Could you kindly share the log if you can recreate it?

I am experiencing the same error upon installing @azure/storage-blob v12.2.0, which goes away after downgrading to v12.1.0.

I wonder if it is related to a change in the latest @azure/core-http v1.1.8. @jonathantzh is it possible for you to try pinning @azure/core-http 1.1.7 while using @azure/storage-blob v12.2.0?

@jeremymeng Pinning @azure/core-http to v1.1.7 while using @azure/storage-blob v12.2.0 does not resolve the issue for me

I have the same problem

Tried reproducing with the logging but now I'm getting a different error, not sure if it's related or not:

##[error]<?xml version="1.0" encoding="utf-8"?><Error><Code>AuthenticationFailed</Code><Message>Server failed to authenticate the request. Make sure the value of Authorization header is formed correctly including the signature.
RequestId:7e1386f2-401e-0066-224a-88c8cb000000
Time:2020-09-11T14:47:26.4664319Z</Message><AuthenticationErrorDetail>The MAC signature found in the HTTP request 'p3JVH1/guDEuSD/Q1wpnZq4bQqmmBW5+BZ47HNZwSl8=' is not the same as any computed signature. Server used following string to sign: 'PUT


5

application/octet-stream






x-ms-client-request-id:91e39802-68d3-453c-b8cb-e9a16eb7b14a
x-ms-date:Fri, 11 Sep 2020 14:47:26 GMT
x-ms-version:2019-07-07
/vscodegithubautomation/]/latest-releases/test-ignore
blockid:ODIyNmZiZWMtYzc4Ni00N2I3LThmZDgtMzc5ZTM2ZDVhZjA4MDAwMDAwMDAwMDAw
comp:block'.</AuthenticationErrorDetail></Error>

Also, I first encountered this in a GitHub action -- https://github.com/microsoft/vscode/runs/1099066807?check_suite_focus=true, which is running on linux.

For those who can recreate it, could you turn on the log and share me the logs via
ts import { setLogLevel } from "@azure/logger"; setLogLevel("info");
I'd like to figure out the root cause instead of simply roll back.

And for anyone who encounter this issue, if v12.1.0 isn't enough for you, please let me know and we will release a hotfix to undo the uploadStream change but with all other new features and bug fixes if we can't find the right fix in time.

Tried reproducing with the logging but now I'm getting a different error, not sure if it's related or not:

##[error]<?xml version="1.0" encoding="utf-8"?><Error><Code>AuthenticationFailed</Code><Message>Server failed to authenticate the request. Make sure the value of Authorization header is formed correctly including the signature.
RequestId:7e1386f2-401e-0066-224a-88c8cb000000
Time:2020-09-11T14:47:26.4664319Z</Message><AuthenticationErrorDetail>The MAC signature found in the HTTP request 'p3JVH1/guDEuSD/Q1wpnZq4bQqmmBW5+BZ47HNZwSl8=' is not the same as any computed signature. Server used following string to sign: 'PUT


5

application/octet-stream






x-ms-client-request-id:91e39802-68d3-453c-b8cb-e9a16eb7b14a
x-ms-date:Fri, 11 Sep 2020 14:47:26 GMT
x-ms-version:2019-07-07
/vscodegithubautomation/]/latest-releases/test-ignore
blockid:ODIyNmZiZWMtYzc4Ni00N2I3LThmZDgtMzc5ZTM2ZDVhZjA4MDAwMDAwMDAwMDAw
comp:block'.</AuthenticationErrorDetail></Error>

@JacksonKearl Probably unrelated.

I try to run the live tests on using Node v12 on Linux/Windows/MacOS. So far the only failures are on MacOS the failed tests is the same as the first failure in #11163. I couldn't repro the second, Invalid Verb, failure though

Experiencing the same, but not on only on 12.2, on 12.0.0 and 12.1.0 as well. Seems that the issue is not relative directly to the storage sdk.

@jeremymeng Pinning @azure/core-http to v1.1.7 while using @azure/storage-blob v12.2.0 does not resolve the issue for me

When pinning to core-http 1.1.7, could you please also check your package-lock.json to verify that core-http 1.1.8 is not pulled in?

@jeremymeng Tried deleting package-lock.json and node_modules folder in @azure/[email protected] package, pinned @azure/core-http version to v1.1.7 in package.json, ran npm install and verified version using npm list @azure/core-http with result:

/@azure/storage-blob
├── @azure/[email protected]
└─┬ @azure/[email protected]
└── @azure/[email protected] deduped

@ljian3377 , Don't know if it's still relevant, but happens for me on Windows. Will attach my logs.

I also ran some other versions, 12.2.0-dev.20200901.1 and 12.2.0-alpha.20200903.1. 12.2.0-dev.20200901.1 _worked_, but 12.2.0-alpha.20200903.1 did not. I attached logs from 12.2.0 and 12.2.0-dev.20200901.1.

12.2.0

[Node] azure:core-http:info ServiceClient: using custom request policies
[Node] azure:core-http:info ServiceClient: using custom request policies
[Node] azure:core-http:info ServiceClient: using custom request policies
[Node] azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
[Node] azure:storage-blob:info Request: {
[Node]   "streamResponseBody": false,
[Node]   "url": "<redacted>/076998c5-c7e5-4e70-8c34-9d61046b9464.pdf?blockid=YmFlNjdhYmItNGYwNC00NjdmLThlZWItZTcxMzk2Yzc2YWVkMDAwMDAwMDAwMDAw&comp=block",
[Node]   "method": "PUT",
[Node]   "headers": {
[Node]     "_headersMap": {
[Node]       "content-type": "application/octet-stream",
[Node]       "content-length": "42231",
[Node]       "x-ms-version": "2019-12-12",
[Node]       "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v12.16.3; Windows_NT 10.0.19042)",
[Node]       "x-ms-client-request-id": "76b2813e-8f88-4227-81c5-5e7e8c930226"
[Node]     }
[Node]   },
[Node]   "withCredentials": false,
[Node]   "timeout": 0,
[Node]   "keepAlive": true,
[Node]   "requestId": "76b2813e-8f88-4227-81c5-5e7e8c930226"
[Node] }
[Node] azure:storage-blob:info Response status code: 201
[Node] azure:storage-blob:info Headers: {
[Node]   "_headersMap": {
[Node]     "content-length": "0",
[Node]     "date": "Sun, 13 Sep 2020 19:25:33 GMT",
[Node]     "server": "Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0",
[Node]     "x-ms-client-request-id": "76b2813e-8f88-4227-81c5-5e7e8c930226",
[Node]     "x-ms-content-crc64": "X181cPKpCPw=",
[Node]     "x-ms-request-id": "d0344ea5-901e-010b-2c03-8a68f7000000",
[Node]     "x-ms-request-server-encrypted": "true",
[Node]     "x-ms-version": "2019-12-12"
[Node]   }
[Node] }
[Node] azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
[Node] azure:storage-blob:info Request: {
[Node]   "streamResponseBody": false,
[Node]   "url": "<redacted>/076998c5-c7e5-4e70-8c34-9d61046b9464.pdf?comp=blocklist",
[Node]   "method": "PUT",
[Node]   "headers": {
[Node]     "_headersMap": {
[Node]       "content-type": "application/xml; charset=utf-8",
[Node]       "x-ms-version": "2019-12-12",
[Node]       "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v12.16.3; Windows_NT 10.0.19042)",
[Node]       "x-ms-client-request-id": "dd013a81-b1ef-4cb4-a20c-7e4115ff06a9"
[Node]     }
[Node]   },
[Node]   "withCredentials": false,
[Node]   "timeout": 0,
[Node]   "keepAlive": true,
[Node]   "requestId": "dd013a81-b1ef-4cb4-a20c-7e4115ff06a9"
[Node] }
[Node] azure:storage-blob:info Response status code: 400
[Node] azure:storage-blob:info Headers: {
[Node]   "_headersMap": {
[Node]     "connection": "close",
[Node]     "content-length": "326",
[Node]     "content-type": "text/html; charset=us-ascii",
[Node]     "date": "Sun, 13 Sep 2020 19:25:33 GMT",
[Node]     "server": "Microsoft-HTTPAPI/2.0"
[Node]   }
[Node] }
[Node] 2020-09-13T19:25:33.635Z v1.0.0 [error] Error uploading files to blob storage. Ex: RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
[Node] <HTML><HEAD><TITLE>Bad Request</TITLE>
[Node] <META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
[Node] <BODY><h2>Bad Request - Invalid Verb</h2>
[Node] <hr><p>HTTP Error 400. The request verb is invalid.</p>
[Node] </BODY></HTML>
[Node]
[Node] 2020-09-13T19:25:33.637Z v1.0.0 [error] RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
[Node] <HTML><HEAD><TITLE>Bad Request</TITLE>
[Node] <META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
[Node] <BODY><h2>Bad Request - Invalid Verb</h2>
[Node] <hr><p>HTTP Error 400. The request verb is invalid.</p>
[Node] </BODY></HTML>
[Node]
[Node]     at new RestError (<redacted>\node_modules\@azure\core-http\dist\index.js:2237:28)
[Node]     at <redacted>\node_modules\@azure\core-http\dist\index.js:3030:25
[Node]     at processTicksAndRejections (internal/process/task_queues.js:97:5)

12.2.0-dev.20200901.1

[Node] azure:core-http:info ServiceClient: using custom request policies
[Node] azure:core-http:info ServiceClient: using custom request policies
[Node] azure:core-http:info ServiceClient: using custom request policies
[Node] upload
[Node] azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
[Node] azure:storage-blob:info Request: {
[Node]   "streamResponseBody": false,
[Node]   "url": "<redacted>/46c30e91-ea6b-4f0c-be26-a2e9b6342db4.pdf?blockid=ZDZhNWYyMDktNThjYi00NTE2LWIzMDEtMjBkYzY0YTA0YzJlMDAwMDAwMDAwMDAw&comp=block",
[Node]   "method": "PUT",
[Node]   "headers": {
[Node]     "_headersMap": {
[Node]       "content-type": "application/octet-stream",
[Node]       "content-length": "42231",
[Node]       "x-ms-version": "2019-12-12",
[Node]       "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v12.16.3; Windows_NT 10.0.19042)",
[Node]       "x-ms-client-request-id": "046b1bf4-1cad-4f91-85f0-a521b02047ec"
[Node]     }
[Node]   },
[Node]   "withCredentials": false,
[Node]   "timeout": 0,
[Node]   "keepAlive": true,
[Node]   "requestId": "046b1bf4-1cad-4f91-85f0-a521b02047ec"
[Node] }
[Node] azure:storage-blob:info Response status code: 201
[Node] azure:storage-blob:info Headers: {
[Node]   "_headersMap": {
[Node]     "content-length": "0",
[Node]     "date": "Sun, 13 Sep 2020 20:07:10 GMT",
[Node]     "server": "Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0",
[Node]     "x-ms-client-request-id": "046b1bf4-1cad-4f91-85f0-a521b02047ec",
[Node]     "x-ms-content-crc64": "X181cPKpCPw=",
[Node]     "x-ms-request-id": "d2aa4be1-101e-0051-6209-8a2823000000",
[Node]     "x-ms-request-server-encrypted": "true",
[Node]     "x-ms-version": "2019-12-12"
[Node]   }
[Node] }
[Node] azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
[Node] azure:storage-blob:info Request: {
[Node]   "streamResponseBody": false,
[Node]   "url": "<redacted>/46c30e91-ea6b-4f0c-be26-a2e9b6342db4.pdf?comp=blocklist",
[Node]   "method": "PUT",
[Node]   "headers": {
[Node]     "_headersMap": {
[Node]       "content-type": "application/xml; charset=utf-8",
[Node]       "x-ms-version": "2019-12-12",
[Node]       "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v12.16.3; Windows_NT 10.0.19042)",
[Node]       "x-ms-client-request-id": "07246208-b088-4076-ad76-caeef5f60ed7"
[Node]     }
[Node]   },
[Node]   "withCredentials": false,
[Node]   "timeout": 0,
[Node]   "keepAlive": true,
[Node]   "requestId": "07246208-b088-4076-ad76-caeef5f60ed7"
[Node] }
[Node] azure:storage-blob:info Response status code: 201
[Node] azure:storage-blob:info Headers: {
[Node]   "_headersMap": {
[Node]     "content-length": "0",
[Node]     "date": "Sun, 13 Sep 2020 20:07:10 GMT",
[Node]     "etag": "\"0x8D8582099945DD3\"",
[Node]     "last-modified": "Sun, 13 Sep 2020 20:07:11 GMT",
[Node]     "server": "Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0",
[Node]     "x-ms-client-request-id": "07246208-b088-4076-ad76-caeef5f60ed7",
[Node]     "x-ms-content-crc64": "uFYdO3euOCk=",
[Node]     "x-ms-request-id": "d2aa4be7-101e-0051-6609-8a2823000000",
[Node]     "x-ms-request-server-encrypted": "true",
[Node]     "x-ms-version": "2019-12-12"
[Node]   }
[Node] }

@patrikmolsson
How often did it fail for you for the 12.2.0 version?

@jeremymeng
The error is from the http server rather than our storage service. So we narrow down this to some underlying http layer issue. Is there any log that we can turn on to know what http requests were exactly sent in the end?

@ljian3377 so the failing request didn't even reach service code, and looked like was rejected by IIS? It's weird to get invalid http verb error as we used PUT as logs showed. Maybe something else caused the error.

We don't log more lower level info than shown above in core-http. We redact sensitive info, and do not log bodies.

One of the other easy ways to is to use fiddler as a proxy and allow fiddler to decrypt https traffic so we can inspect raw requests and responses.

https://www.donovanbrown.com/post/How-to-debug-your-Nodejs-app-with-Fiddler

https://medium.com/swlh/hacking-the-web-with-fiddler-72d026eee6bd#:~:text=Fiddler%20allows%20you%20to%20decrypt,certificate%20and%20enabling%20HTTPS%20decryption.&text=First%2C%20start%20Fiddler%20on%20the,says%20%E2%80%9CDecrypt%20HTTPS%20Traffic%E2%80%9D.

https://httptoolkit.tech/javascript seems useful for intercepting HTTP(S) traffic. Never used it though.

Good news. Successuflly recreated it locally. Will look into the Fiddler tracing.

I see the failure in #11163 in my custom runs which is also the same invalid verb failure. I logged requests, however, the logs didn't show anything unusual at first glance https://dev.azure.com/azure-sdk/internal/_build/results?buildId=535651&view=logs&j=34d05327-3286-5fd0-44d3-76aebff5d924&t=d726e143-6308-5465-2a45-ec34d6ea866c

@patrikmolsson @JacksonKearl
Could you help share us the Fiddler tracing if you can recreate it? I failed to recreate it when I use Fiddler as the proxy with these env.

HTTP_PROXY=http://127.0.0.1:8888 
HTTPS_PROXY=http://127.0.0.1:8888
NODE_TLS_REJECT_UNAUTHORIZED=0

Patrik has this issue consistenly. But when he tried with the Fiddler proxy in the way above, it doesn't fail any more.
Also tried with stageBlock then commitBlockList instead of uploadStream and it didn't fail for him either.

I've hit this error as well when try to upload multiple images sequentially

azure:core-http:info ServiceClient: using custom request policies
azure:core-http:info ServiceClient: using custom request policies
azure:core-http:info ServiceClient: using custom request policies
azure:core-http:info ServiceClient: using custom request policies
azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
azure:storage-blob:info Request: {
  "streamResponseBody": false,
  "url": "https://xxxxxx.blob.core.windows.net/yyyyyy/9231882262682516-CleanShot%202020-09-09%20at%2018.03.25.png?blockid=NzczY2I4ZWYtZmJhZi00MWI1LWJiZTktZWUxOTk0YjNjYWQzMDAwMDAwMDAwMDAw&comp=block",
  "method": "PUT",
  "headers": {
    "_headersMap": {
      "content-type": "application/octet-stream",
      "content-length": "176320",
      "x-ms-version": "2019-12-12",
      "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
      "x-ms-client-request-id": "b2fd5314-4055-4acf-8815-6a7a8dc5984d"
    }
  },
  "withCredentials": false,
  "timeout": 0,
  "keepAlive": true,
  "requestId": "b2fd5314-4055-4acf-8815-6a7a8dc5984d"
}
azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
azure:storage-blob:info Request: {
  "streamResponseBody": false,
  "url": "https://xxxxxxx.blob.core.windows.net/yyyyyyy/22309202784150783-CleanShot%202020-09-09%20at%2018.06.11.png?blockid=ZDY4ODM3M2QtZDhhOC00ZjZjLTg3MzYtZmU2N2MxNDMyYTdhMDAwMDAwMDAwMDAw&comp=block",
  "method": "PUT",
  "headers": {
    "_headersMap": {
      "content-type": "application/octet-stream",
      "content-length": "556245",
      "x-ms-version": "2019-12-12",
      "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
      "x-ms-client-request-id": "797e7b23-0568-4412-9415-88ef67619c83"
    }
  },
  "withCredentials": false,
  "timeout": 0,
  "keepAlive": true,
  "requestId": "797e7b23-0568-4412-9415-88ef67619c83"
}
azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
azure:storage-blob:info Request: {
  "streamResponseBody": false,
  "url": "https://xxxxx.blob.core.windows.net/yyyyyy/25700712822304417-CleanShot%202020-09-09%20at%2018.06.11.png?blockid=OTMyOTM1ZDAtZjdhMi00Zjg5LWE4MjUtYjJlMzU0YmUzMWQzMDAwMDAwMDAwMDAw&comp=block",
  "method": "PUT",
  "headers": {
    "_headersMap": {
      "content-type": "application/octet-stream",
      "content-length": "556245",
      "x-ms-version": "2019-12-12",
      "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
      "x-ms-client-request-id": "a573e2cc-077f-4b5d-8f71-bced9fa16213"
    }
  },
  "withCredentials": false,
  "timeout": 0,
  "keepAlive": true,
  "requestId": "a573e2cc-077f-4b5d-8f71-bced9fa16213"
}
azure:storage-blob:info Response status code: 201
azure:storage-blob:info Headers: {
  "_headersMap": {
    "content-length": "0",
    "date": "Tue, 15 Sep 2020 10:53:39 GMT",
    "server": "Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0",
    "x-ms-client-request-id": "b2fd5314-4055-4acf-8815-6a7a8dc5984d",
    "x-ms-content-crc64": "SQ19ShmoyEE=",
    "x-ms-request-id": "2305562e-f01e-0004-274e-8b8ee7000000",
    "x-ms-request-server-encrypted": "true",
    "x-ms-version": "2019-12-12"
  }
}
azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
azure:storage-blob:info Request: {
  "streamResponseBody": false,
  "url": "https://xxxxx.blob.core.windows.net/yyyyyy/9231882262682516-CleanShot%202020-09-09%20at%2018.03.25.png?comp=blocklist",
  "method": "PUT",
  "headers": {
    "_headersMap": {
      "content-type": "application/xml; charset=utf-8",
      "x-ms-version": "2019-12-12",
      "x-ms-blob-content-type": "image/png",
      "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
      "x-ms-client-request-id": "fd2608ae-6428-49b4-9f11-c1665d27c032"
    }
  },
  "withCredentials": false,
  "timeout": 0,
  "keepAlive": true,
  "requestId": "fd2608ae-6428-49b4-9f11-c1665d27c032"
}
azure:storage-blob:info Response status code: 400
azure:storage-blob:info Headers: {
  "_headersMap": {
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "date": "Tue, 15 Sep 2020 10:53:39 GMT",
    "server": "Microsoft-HTTPAPI/2.0"
  }
}
NODE_PROMISE_REJECT:  Promise {
  <rejected> RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Bad Request</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Bad Request - Invalid Verb</h2>
<hr><p>HTTP Error 400. The request verb is invalid.</p>
</BODY></HTML>

 {
  "name": "RestError",
  "statusCode": 400,
  "request": {
    "streamResponseBody": false,
    "url": "https://xxxxx.blob.core.windows.net/yyyyyy/9231882262682516-CleanShot%202020-09-09%20at%2018.03.25.png?comp=REDACTED",
    "method": "PUT",
    "headers": {
      "_headersMap": {
        "content-type": "application/xml; charset=utf-8",
        "x-ms-version": "REDACTED",
        "x-ms-blob-content-type": "REDACTED",
        "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
        "x-ms-client-request-id": "fd2608ae-6428-49b4-9f11-c1665d27c032",
        "x-ms-date": "REDACTED",
        "content-length": "159",
        "authorization": "REDACTED",
        "cookie": "REDACTED"
      }
    },
    "withCredentials": false,
    "timeout": 0,
    "keepAlive": true,
    "decompressResponse": false,
    "requestId": "fd2608ae-6428-49b4-9f11-c1665d27c032"
  },
  "details": {
    "date": "2020-09-15T10:53:39.000Z",
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "server": "Microsoft-HTTPAPI/2.0"
  },
  "message": "<!DOCTYPE HTML PUBLIC \"-//W3C//DTD HTML 4.01//EN\"\"http://www.w3.org/TR/html4/strict.dtd\">\r\n<HTML><HEAD><TITLE>Bad Request</TITLE>\r\n<META HTTP-EQUIV=\"Content-Type\" Content=\"text/html; charset=us-ascii\"></HEAD>\r\n<BODY><h2>Bad Request - Invalid Verb</h2>\r\n<hr><p>HTTP Error 400. The request verb is invalid.</p>\r\n</BODY></HTML>\r\n"
} }  Error:  RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Bad Request</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Bad Request - Invalid Verb</h2>
<hr><p>HTTP Error 400. The request verb is invalid.</p>
</BODY></HTML>

 {
  "name": "RestError",
  "statusCode": 400,
  "request": {
    "streamResponseBody": false,
    "url": "https://xxxxx.blob.core.windows.net/yyyyyy/9231882262682516-CleanShot%202020-09-09%20at%2018.03.25.png?comp=REDACTED",
    "method": "PUT",
    "headers": {
      "_headersMap": {
        "content-type": "application/xml; charset=utf-8",
        "x-ms-version": "REDACTED",
        "x-ms-blob-content-type": "REDACTED",
        "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
        "x-ms-client-request-id": "fd2608ae-6428-49b4-9f11-c1665d27c032",
        "x-ms-date": "REDACTED",
        "content-length": "159",
        "authorization": "REDACTED",
        "cookie": "REDACTED"
      }
    },
    "withCredentials": false,
    "timeout": 0,
    "keepAlive": true,
    "decompressResponse": false,
    "requestId": "fd2608ae-6428-49b4-9f11-c1665d27c032"
  },
  "details": {
    "date": "2020-09-15T10:53:39.000Z",
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "server": "Microsoft-HTTPAPI/2.0"
  },
  "message": "<!DOCTYPE HTML PUBLIC \"-//W3C//DTD HTML 4.01//EN\"\"http://www.w3.org/TR/html4/strict.dtd\">\r\n<HTML><HEAD><TITLE>Bad Request</TITLE>\r\n<META HTTP-EQUIV=\"Content-Type\" Content=\"text/html; charset=us-ascii\"></HEAD>\r\n<BODY><h2>Bad Request - Invalid Verb</h2>\r\n<hr><p>HTTP Error 400. The request verb is invalid.</p>\r\n</BODY></HTML>\r\n"
}
azure:storage-blob:info Response status code: 201
azure:storage-blob:info Headers: {
  "_headersMap": {
    "content-length": "0",
    "date": "Tue, 15 Sep 2020 10:53:40 GMT",
    "server": "Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0",
    "x-ms-client-request-id": "a573e2cc-077f-4b5d-8f71-bced9fa16213",
    "x-ms-content-crc64": "5SImHhoehV0=",
    "x-ms-request-id": "18de8c36-701e-001a-094e-8b623f000000",
    "x-ms-request-server-encrypted": "true",
    "x-ms-version": "2019-12-12"
  }
}
azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
azure:storage-blob:info Request: {
  "streamResponseBody": false,
  "url": "https://xxxxx.blob.core.windows.net/yyyyyy/25700712822304417-CleanShot%202020-09-09%20at%2018.06.11.png?comp=blocklist",
  "method": "PUT",
  "headers": {
    "_headersMap": {
      "content-type": "application/xml; charset=utf-8",
      "x-ms-version": "2019-12-12",
      "x-ms-blob-content-type": "image/png",
      "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
      "x-ms-client-request-id": "0ec0e702-20cc-45d5-ac01-57188747b420"
    }
  },
  "withCredentials": false,
  "timeout": 0,
  "keepAlive": true,
  "requestId": "0ec0e702-20cc-45d5-ac01-57188747b420"
}
azure:storage-blob:info Response status code: 400
azure:storage-blob:info Headers: {
  "_headersMap": {
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "date": "Tue, 15 Sep 2020 10:53:40 GMT",
    "server": "Microsoft-HTTPAPI/2.0"
  }
}
NODE_PROMISE_REJECT:  Promise {
  <rejected> RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Bad Request</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Bad Request - Invalid Verb</h2>
<hr><p>HTTP Error 400. The request verb is invalid.</p>
</BODY></HTML>

 {
  "name": "RestError",
  "statusCode": 400,
  "request": {
    "streamResponseBody": false,
    "url": "https://xxxxx.blob.core.windows.net/yyyyyy/25700712822304417-CleanShot%202020-09-09%20at%2018.06.11.png?comp=REDACTED",
    "method": "PUT",
    "headers": {
      "_headersMap": {
        "content-type": "application/xml; charset=utf-8",
        "x-ms-version": "REDACTED",
        "x-ms-blob-content-type": "REDACTED",
        "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
        "x-ms-client-request-id": "0ec0e702-20cc-45d5-ac01-57188747b420",
        "x-ms-date": "REDACTED",
        "content-length": "159",
        "authorization": "REDACTED",
        "cookie": "REDACTED"
      }
    },
    "withCredentials": false,
    "timeout": 0,
    "keepAlive": true,
    "decompressResponse": false,
    "requestId": "0ec0e702-20cc-45d5-ac01-57188747b420"
  },
  "details": {
    "date": "2020-09-15T10:53:40.000Z",
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "server": "Microsoft-HTTPAPI/2.0"
  },
  "message": "<!DOCTYPE HTML PUBLIC \"-//W3C//DTD HTML 4.01//EN\"\"http://www.w3.org/TR/html4/strict.dtd\">\r\n<HTML><HEAD><TITLE>Bad Request</TITLE>\r\n<META HTTP-EQUIV=\"Content-Type\" Content=\"text/html; charset=us-ascii\"></HEAD>\r\n<BODY><h2>Bad Request - Invalid Verb</h2>\r\n<hr><p>HTTP Error 400. The request verb is invalid.</p>\r\n</BODY></HTML>\r\n"
} }  Error:  RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Bad Request</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Bad Request - Invalid Verb</h2>
<hr><p>HTTP Error 400. The request verb is invalid.</p>
</BODY></HTML>

 {
  "name": "RestError",
  "statusCode": 400,
  "request": {
    "streamResponseBody": false,
    "url": "https://xxxxx.blob.core.windows.net/yyyyyy/25700712822304417-CleanShot%202020-09-09%20at%2018.06.11.png?comp=REDACTED",
    "method": "PUT",
    "headers": {
      "_headersMap": {
        "content-type": "application/xml; charset=utf-8",
        "x-ms-version": "REDACTED",
        "x-ms-blob-content-type": "REDACTED",
        "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
        "x-ms-client-request-id": "0ec0e702-20cc-45d5-ac01-57188747b420",
        "x-ms-date": "REDACTED",
        "content-length": "159",
        "authorization": "REDACTED",
        "cookie": "REDACTED"
      }
    },
    "withCredentials": false,
    "timeout": 0,
    "keepAlive": true,
    "decompressResponse": false,
    "requestId": "0ec0e702-20cc-45d5-ac01-57188747b420"
  },
  "details": {
    "date": "2020-09-15T10:53:40.000Z",
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "server": "Microsoft-HTTPAPI/2.0"
  },
  "message": "<!DOCTYPE HTML PUBLIC \"-//W3C//DTD HTML 4.01//EN\"\"http://www.w3.org/TR/html4/strict.dtd\">\r\n<HTML><HEAD><TITLE>Bad Request</TITLE>\r\n<META HTTP-EQUIV=\"Content-Type\" Content=\"text/html; charset=us-ascii\"></HEAD>\r\n<BODY><h2>Bad Request - Invalid Verb</h2>\r\n<hr><p>HTTP Error 400. The request verb is invalid.</p>\r\n</BODY></HTML>\r\n"
}
azure:storage-blob:info Response status code: 201
azure:storage-blob:info Headers: {
  "_headersMap": {
    "content-length": "0",
    "date": "Tue, 15 Sep 2020 10:53:40 GMT",
    "server": "Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0",
    "x-ms-client-request-id": "797e7b23-0568-4412-9415-88ef67619c83",
    "x-ms-content-crc64": "5SImHhoehV0=",
    "x-ms-request-id": "e1dac692-801e-0031-6f4e-8be2f3000000",
    "x-ms-request-server-encrypted": "true",
    "x-ms-version": "2019-12-12"
  }
}
azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
azure:storage-blob:info Request: {
  "streamResponseBody": false,
  "url": "https://xxxxx.blob.core.windows.net/yyyyyy/22309202784150783-CleanShot%202020-09-09%20at%2018.06.11.png?comp=blocklist",
  "method": "PUT",
  "headers": {
    "_headersMap": {
      "content-type": "application/xml; charset=utf-8",
      "x-ms-version": "2019-12-12",
      "x-ms-blob-content-type": "image/png",
      "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
      "x-ms-client-request-id": "22340820-7594-4304-858f-0fbee39ea0bb"
    }
  },
  "withCredentials": false,
  "timeout": 0,
  "keepAlive": true,
  "requestId": "22340820-7594-4304-858f-0fbee39ea0bb"
}
azure:storage-blob:info Response status code: 400
azure:storage-blob:info Headers: {
  "_headersMap": {
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "date": "Tue, 15 Sep 2020 10:53:40 GMT",
    "server": "Microsoft-HTTPAPI/2.0"
  }
}
NODE_PROMISE_REJECT:  Promise {
  <rejected> RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Bad Request</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Bad Request - Invalid Verb</h2>
<hr><p>HTTP Error 400. The request verb is invalid.</p>
</BODY></HTML>

 {
  "name": "RestError",
  "statusCode": 400,
  "request": {
    "streamResponseBody": false,
    "url": "https://xxxxx.blob.core.windows.net/yyyyyy/22309202784150783-CleanShot%202020-09-09%20at%2018.06.11.png?comp=REDACTED",
    "method": "PUT",
    "headers": {
      "_headersMap": {
        "content-type": "application/xml; charset=utf-8",
        "x-ms-version": "REDACTED",
        "x-ms-blob-content-type": "REDACTED",
        "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
        "x-ms-client-request-id": "22340820-7594-4304-858f-0fbee39ea0bb",
        "x-ms-date": "REDACTED",
        "content-length": "159",
        "authorization": "REDACTED",
        "cookie": "REDACTED"
      }
    },
    "withCredentials": false,
    "timeout": 0,
    "keepAlive": true,
    "decompressResponse": false,
    "requestId": "22340820-7594-4304-858f-0fbee39ea0bb"
  },
  "details": {
    "date": "2020-09-15T10:53:40.000Z",
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "server": "Microsoft-HTTPAPI/2.0"
  },
  "message": "<!DOCTYPE HTML PUBLIC \"-//W3C//DTD HTML 4.01//EN\"\"http://www.w3.org/TR/html4/strict.dtd\">\r\n<HTML><HEAD><TITLE>Bad Request</TITLE>\r\n<META HTTP-EQUIV=\"Content-Type\" Content=\"text/html; charset=us-ascii\"></HEAD>\r\n<BODY><h2>Bad Request - Invalid Verb</h2>\r\n<hr><p>HTTP Error 400. The request verb is invalid.</p>\r\n</BODY></HTML>\r\n"
} }  Error:  RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Bad Request</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Bad Request - Invalid Verb</h2>
<hr><p>HTTP Error 400. The request verb is invalid.</p>
</BODY></HTML>

 {
  "name": "RestError",
  "statusCode": 400,
  "request": {
    "streamResponseBody": false,
    "url": "https://xxxxx.blob.core.windows.net/yyyyyy/22309202784150783-CleanShot%202020-09-09%20at%2018.06.11.png?comp=REDACTED",
    "method": "PUT",
    "headers": {
      "_headersMap": {
        "content-type": "application/xml; charset=utf-8",
        "x-ms-version": "REDACTED",
        "x-ms-blob-content-type": "REDACTED",
        "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v10.14.1; Darwin 19.6.0)",
        "x-ms-client-request-id": "22340820-7594-4304-858f-0fbee39ea0bb",
        "x-ms-date": "REDACTED",
        "content-length": "159",
        "authorization": "REDACTED",
        "cookie": "REDACTED"
      }
    },
    "withCredentials": false,
    "timeout": 0,
    "keepAlive": true,
    "decompressResponse": false,
    "requestId": "22340820-7594-4304-858f-0fbee39ea0bb"
  },
  "details": {
    "date": "2020-09-15T10:53:40.000Z",
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "server": "Microsoft-HTTPAPI/2.0"
  },
  "message": "<!DOCTYPE HTML PUBLIC \"-//W3C//DTD HTML 4.01//EN\"\"http://www.w3.org/TR/html4/strict.dtd\">\r\n<HTML><HEAD><TITLE>Bad Request</TITLE>\r\n<META HTTP-EQUIV=\"Content-Type\" Content=\"text/html; charset=us-ascii\"></HEAD>\r\n<BODY><h2>Bad Request - Invalid Verb</h2>\r\n<hr><p>HTTP Error 400. The request verb is invalid.</p>\r\n</BODY></HTML>\r\n"
}

I consistently hit the same error and see a very similar log to that posted by @brianpham93 .

It occurs when using the uploadStream function to upload a stream read from a small text file. upload seems to work as expected.
I can reproduce it on a Docker container (FROM node:12) and on Windows 10.

Downgrading to version 12.1.2 makes the issue go away.

"user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v12.18.2; Windows_NT 10.0.19041)",

azure:core-http:info ServiceClient: using custom request policies
azure:core-http:info ServiceClient: using custom request policies
azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
azure:storage-blob:info Request: {
  "streamResponseBody": false,
  "url": "https://REDACTED.txt?blockid=REDACTED&comp=block",
  "method": "PUT",
  "headers": {
    "_headersMap": {
      "content-type": "application/octet-stream",
      "content-length": "9",
      "x-ms-version": "2019-12-12",
      "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v12.18.2; Windows_NT 10.0.19041)",
      "x-ms-client-request-id": "acb393d6-2674-48c6-aab1-e4cac71e063b"
    }
  },
  "withCredentials": false,
  "timeout": 0,
  "keepAlive": true,
  "requestId": "acb393d6-2674-48c6-aab1-e4cac71e063b"
}
azure:storage-blob:info Response status code: 201
azure:storage-blob:info Headers: {
  "_headersMap": {
    "content-length": "0",
    "date": "Tue, 15 Sep 2020 09:43:20 GMT",
    "server": "Windows-Azure-Blob/1.0 Microsoft-HTTPAPI/2.0",
    "x-ms-client-request-id": "acb393d6-2674-48c6-aab1-e4cac71e063b",
    "x-ms-content-crc64": "REDACTED",
    "x-ms-request-id": "73b16532-d01e-0019-2144-8bb674000000",
    "x-ms-request-server-encrypted": "true",
    "x-ms-version": "2019-12-12"
  }
}
azure:storage-blob:info RetryPolicy: =====> Try=1 Primary
azure:storage-blob:info Request: {
  "streamResponseBody": false,
  "url": "https://REDACTED?comp=blocklist",
  "method": "PUT",
  "headers": {
    "_headersMap": {
      "content-type": "application/xml; charset=utf-8",
      "x-ms-version": "2019-12-12",
      "user-agent": "azsdk-js-storageblob/12.2.0 (NODE-VERSION v12.18.2; Windows_NT 10.0.19041)",
      "x-ms-client-request-id": "c07bec42-53c0-4ae7-84df-973407c93b71"
    }
  },
  "withCredentials": false,
  "timeout": 0,
  "keepAlive": true,
  "requestId": "c07bec42-53c0-4ae7-84df-973407c93b71"
}
azure:storage-blob:info Response status code: 400
azure:storage-blob:info Headers: {
  "_headersMap": {
    "connection": "close",
    "content-length": "326",
    "content-type": "text/html; charset=us-ascii",
    "date": "Tue, 15 Sep 2020 09:43:20 GMT",
    "server": "Microsoft-HTTPAPI/2.0"
  }
}
(node:14008) UnhandledPromiseRejectionWarning: RestError: <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
<HTML><HEAD><TITLE>Bad Request</TITLE>
<META HTTP-EQUIV="Content-Type" Content="text/html; charset=us-ascii"></HEAD>
<BODY><h2>Bad Request - Invalid Verb</h2>
<hr><p>HTTP Error 400. The request verb is invalid.</p>
</BODY></HTML>

    at new RestError (C:\...\node_modules\@azure\core-http\dist\index.js:2237:28)
    at C:\...\node_modules\@azure\core-http\dist\index.js:3030:25
    at processTicksAndRejections (internal/process/task_queues.js:97:5)

The bug is related to the stream length.

any workaround we can apply to avoid this temporarily ?

any workaround we can apply to avoid this temporarily ?

A fix is coming soon. Before that, could you call uploadFile for file, or stageBlock and commitBlockList individually.

      const body = () => yourStream;
      await blockBlobClient.stageBlock(base64encode("1"), body, body.length);
      await blockBlobClient.stageBlock(base64encode("2"), body2, body2.length);
      await blockBlobClient.commitBlockList([base64encode("1"), base64encode("2")]);

Also, disabling keep-alive will also work.

    const pipeline = newPipeline(credential, {
      keepAliveOptions: {
        enable: false
      }
    });

    const blobPrimaryURL = `https://${credential.accountName}${accountNameSuffix}.blob.core.windows.net/`;
    return new BlobServiceClient(blobPrimaryURL, pipeline);

Bug located and a hot fix is coming soon. Caused by sending data longer than specified by content-length.

@jeremymeng
Could the node-fetch throw when the stream length (the input is a stream factory) doesn't match the content-length?

But if the root cause is the body ()=>ReadableStream is longer than the specified content length while the http client and the server are respecting the content length we set, then this case should fail consistently if keep-alive is enabled.
It is now failing consistently for me but didn't fail yesterday. What's default keep-alive setting of core-http in Node.js?
https://github.com/Azure/azure-sdk-for-js/blob/e8840e7d00a54dbf1a903170a7f7a1113b416f2a/sdk/storage/storage-blob/test/node/highlevel.node.spec.ts#L270

Could the node-fetch throw when the stream length (the input is a stream factory) doesn't match the content-length?

I don't think stream has a length, or did I miss anything?

It is now failing consistently for me but didn't fail yesterday. What's default keep-alive setting of core-http in Node.js?

keep-alive is enabled by default. Only storage libraries use keep-alive. I remember @XiaoningLiu added the keep-alive support but I couldn't locate the history.

I don't think stream has a length, or did I miss anything?

The input is a stream factory. So theoretically you can count the length before hand but is just inefficient.

We belive this issue is addressed in the hotfix: @azure/[email protected] and @azure/[email protected]
Let me know if not.

Was this page helpful?
0 / 5 - 0 ratings