Azurite
Azurite copied to clipboard
Azure
[blob-storage] BlockBlobClient.upload with progress event returns 400
Which service(blob, file, queue, table) does this issue concern?
blob
Which version of the Azurite was used?
3.3.0-preview
Where do you get Azurite? (npm, DockerHub, NuGet, Visual Studio Code Extension)
npm
What's the Node.js version?
v12.13.0
What problem was encountered?
Unit test failure: BlockBlobClient. upload with progress report
await blockBlobClient.upload(body, body.length, {
onProgress: () => {}
});
Return 400 error code. The connection seems to be closed before azurite gives its response.
response: {
body: '',
headers: HttpHeaders { _headersMap: [Object] },
status: 400,
parsedHeaders: {
etag: undefined,
lastModified: undefined,
contentMD5: undefined,
clientRequestId: undefined,
requestId: undefined,
version: undefined,
date: undefined,
isServerEncrypted: undefined,
encryptionKeySha256: undefined,
errorCode: undefined,
connection: 'close'
}
}
Output of Azurite:
127.0.0.1 - - [13/Dec/2019:07:01:39 +0000] "PUT /devstoreaccount1/container157622049994001201?restype=container HTTP/1.1" 201 -
127.0.0.1 - - [13/Dec/2019:07:01:39 +0000] "PUT /devstoreaccount1/container157622049994001201/blob157622049998604949 HTTP/1.1" - -
Return Code is missing for the blob upload operation.
Steps to reproduce the issue?
Re-run the test-case.
Have you found a mitigation/solution?
N/A
debug.log
2019-12-13T07:01:39.997Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: BlobStorageContextMiddleware: RequestMethod=PUT RequestURL=http://127.0.0.1/devstoreaccount1/container157622049994001201/blob157622049998604949 RequestHeaders:{"content-type":"application/octet-stream","content-length":"30","x-ms-version":"2019-02-02","x-ms-blob-type":"BlockBlob","user-agent":"azsdk-js-storageblob/12.0.1 (NODE-VERSION v12.13.0; Windows_NT 10.0.18362)","x-ms-client-request-id":"88f953c9-3467-4e73-a7eb-6a6d36eb2b92","x-ms-date":"Fri, 13 Dec 2019 07:01:39 GMT","authorization":"SharedKey devstoreaccount1:mTAp8CFhCSzSedPTdeTCu3v4b43qYFtsEyoWzrrmcQw=","cookie":"","accept":"*/*","accept-encoding":"gzip,deflate","host":"127.0.0.1:10000","connection":"keep-alive"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2019-12-13T07:01:39.997Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=container157622049994001201 Blob=blob157622049998604949
2019-12-13T07:01:39.997Z 78b4350c-35f4-4bac-a46f-05b01f27f102 verbose: DispatchMiddleware: Dispatching request...
2019-12-13T07:01:39.997Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: DispatchMiddleware: Operation=BlockBlob_Upload
2019-12-13T07:01:39.997Z 78b4350c-35f4-4bac-a46f-05b01f27f102 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2019-12-13T07:01:39.997Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: PublicAccessAuthenticator:validate() Start validation against public access.
2019-12-13T07:01:39.997Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: PublicAccessAuthenticator:validate() Getting account properties...
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: container157622049994001201, blob: blob157622049998604949
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container container157622049994001201
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"PUT\n\n\n30\n\napplication/octet-stream\n\n\n\n\n\n\nx-ms-blob-type:BlockBlob\nx-ms-client-request-id:88f953c9-3467-4e73-a7eb-6a6d36eb2b92\nx-ms-date:Fri, 13 Dec 2019 07:01:39 GMT\nx-ms-version:2019-02-02\n/devstoreaccount1/devstoreaccount1/container157622049994001201/blob157622049998604949"
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:mTAp8CFhCSzSedPTdeTCu3v4b43qYFtsEyoWzrrmcQw=
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 verbose: DeserializerMiddleware: Start deserializing...
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: HandlerMiddleware: DeserializedParameters={"options":{"metadata":{},"requestId":"88f953c9-3467-4e73-a7eb-6a6d36eb2b92","blobHTTPHeaders":{},"leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"contentLength":30,"version":"2019-02-02","blobType":"BlockBlob","body":"ReadableStream"}
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue.operate() Schedule incoming job d0597476-0c7c-4d77-b2bc-c3e230ba7050
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue:execute() Current runningConcurrency:0 maxConcurrency:10 operations.length:1
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: FSExtentStore:appendExtent() Select extent from idle location for extent append operation. LocationId:1 extentId:b1851f64-d728-4105-94df-3ab4cb27a1fe offset:277 MAX_EXTENT_SIZE:4194304
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: FSExtentStore:appendExtent() Get fd:4 for extent:b1851f64-d728-4105-94df-3ab4cb27a1fe from cache.
2019-12-13T07:01:39.998Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: FSExtentStore:appendExtent() Start writing to extent b1851f64-d728-4105-94df-3ab4cb27a1fe
2019-12-13T07:01:39.999Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: FSExtentStore:appendExtent() Write finish, start updating extent metadata. extent:{"id":"b1851f64-d728-4105-94df-3ab4cb27a1fe","persistencyId":"Default","path":"b1851f64-d728-4105-94df-3ab4cb27a1fe","size":307,"lastModifiedInMS":1576220499999}
2019-12-13T07:01:39.999Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: FSExtentStore:appendExtent() Update extent metadata done. Resolve()
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue.operate() Job d0597476-0c7c-4d77-b2bc-c3e230ba7050 completes callback, resolve.
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue.operate() Schedule incoming job 5c82dad4-164d-4086-bc91-02096ed99630
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue:execute() Current runningConcurrency:0 maxConcurrency:100 operations.length:1
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 verbose: FSExtentStore:readExtent() Creating read stream. LocationId:Default extentId:b1851f64-d728-4105-94df-3ab4cb27a1fe path:__blobstorage__\b1851f64-d728-4105-94df-3ab4cb27a1fe offset:277 count:30 end:306
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue.operate() Job 5c82dad4-164d-4086-bc91-02096ed99630 completes callback, resolve.
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue:execute() Current runningConcurrency:0 maxConcurrency:10 operations.length:0
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue:execute() return. Operation.length === 0
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue:execute() Current runningConcurrency:0 maxConcurrency:100 operations.length:0
2019-12-13T07:01:40.000Z 78b4350c-35f4-4bac-a46f-05b01f27f102 debug: OperationQueue:execute() return. Operation.length === 0
2019-12-13T07:01:40.010Z 78b4350c-35f4-4bac-a46f-05b01f27f102 verbose: SerializerMiddleware: Start serializing...
2019-12-13T07:01:40.010Z 78b4350c-35f4-4bac-a46f-05b01f27f102 info: EndMiddleware: End response. TotalTimeInMS=13 StatusCode=201 StatusMessage=undefined Headers={"server":"Azurite-Blob/3.3.0-preview","etag":"\"d-KlmqOqy8PzDbE+/Uu7T0QBYCynk\"","last-modified":"Fri, 13 Dec 2019 07:01:39 GMT","content-md5":"UceT76mmV8kt+scFQrj7yQ==","x-ms-client-request-id":"88f953c9-3467-4e73-a7eb-6a6d36eb2b92","x-ms-request-id":"78b4350c-35f4-4bac-a46f-05b01f27f102","x-ms-version":"2019-02-02","date":"Fri, 13 Dec 2019 07:01:39 GMT","x-ms-request-server-encrypted":"true"}
2019-12-13T07:01:40.010Z 78b4350c-35f4-4bac-a46f-05b01f27f102 verbose: FSExtentStore:readExtent() Read stream closed. LocationId:Default extentId:b1851f64-d728-4105-94df-3ab4cb27a1fe path:__blobstorage__\b1851f64-d728-4105-94df-3ab4cb27a1fe offset:277 count:30 end:306
request_id
`` 88f953c9-3467-4e73-a7eb-6a6d36eb2b92
Same problem for
- blockBlobClient: stageBlock with progress report
- PageBlobClient: uploadPages with progress report
The sdk side has fixed an issue related to the onProgress event recently. But Azurite's behavior is consistent before and after the fix.
Cannot confirm it's Azurite or JS SDK issue. Needs further investigation.
This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.
![stale[bot] avatar](https://avatars.githubusercontent.com/in/1724?v=4 "Published by a pub.dev verified publisher"){kind=small}