Azure / Azurite

A lightweight server clone of Azure Storage that simulates most of the commands supported by it with minimal dependencies
MIT License
1.8k stars 320 forks source link

Azurite keeps getting corrupted and the only fix is to delete and re-initialise #1492

Open ADH-LukeBollam opened 2 years ago

ADH-LukeBollam commented 2 years ago

Which service(blob, file, queue, table) does this issue concern?

all

Which version of the Azurite was used?

3.16.0

Where do you get Azurite? (npm, DockerHub, NuGet, Visual Studio Code Extension)

Visual Studio 2022 builtin

What's the Node.js version?

14.17.3

What problem was encountered?

Seemingly randomly, azurite will stop working. Azure Functions can't access queues, my app can't access blobs. It runs because I see the logs saying it's successfully started, but looking at the logs, its trying to access containers that don't exist.

For example, the path to my container is: \AppData\Local\Temp\Azurite__blobstorage__\92192237-4443-4d5a-a178-bab18249bade

But the logs will try to access: 2022-05-12T03:51:17.234Z c4b172fe-4cc1-4997-8887-787f8bc2072d error: ErrorMiddleware: ErrorName=Error ErrorMessage=ENOENT: no such file or directory, open '\AppData\Local\Temp\Azurite__blobstorage__\1ac1c0fa-fe17-4844-b192-f68fdc877e22' ErrorStack="Error: ENOENT: no such file or directory, open '\AppData\Local\Temp\Azurite\blobstorage\1ac1c0fa-fe17-4844-b192-f68fdc877e22'"

my azurite_db_blob.json contains references to both these containers, but only one of them exists on the folder path.

The same thing happens with queues, it tries to access one that doesn't exist

2022-05-12T03:51:19.008Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: QueueStorageContextMiddleware: RequestMethod=GET RequestURL=http://127.0.0.1/devstoreaccount1/import-jobs-poison?comp=metadata RequestHeaders:{"host":"127.0.0.1:10001","x-ms-version":"2018-11-09","accept":"application/xml","x-ms-client-request-id":"b71aeedb-f75e-47f6-927a-b89bebe2f1ac","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Storage.Queues/12.8.0 (.NET Core 3.1.23; Microsoft Windows 10.0.19043)","x-ms-date":"Thu, 12 May 2022 03:51:19 GMT","authorization":"SharedKey devstoreaccount1:ylLXwTHJWdrTvha04ifFBUGsAaPEpyAlfZIpfwDA+qs="} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-05-12T03:51:19.008Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: QueueStorageContextMiddleware: Account=devstoreaccount1 Queue=import-jobs-poison Message=undefined MessageId=undefined
2022-05-12T03:51:19.008Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 verbose: DispatchMiddleware: Dispatching request...
2022-05-12T03:51:19.008Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: DispatchMiddleware: Operation=Queue_GetProperties
2022-05-12T03:51:19.008Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-05-12T03:51:19.008Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: QueueSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-05-12T03:51:19.008Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: QueueSharedKeyAuthenticator:validate() [STRING TO SIGN]:"GET\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:b71aeedb-f75e-47f6-927a-b89bebe2f1ac\nx-ms-date:Thu, 12 May 2022 03:51:19 GMT\nx-ms-return-client-request-id:true\nx-ms-version:2018-11-09\n/devstoreaccount1/devstoreaccount1/import-jobs-poison\ncomp:metadata"
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: QueueSharedKeyAuthenticator:validate() Calculated authentication header based on key1: devstoreaccount1:ylLXwTHJWdrTvha04ifFBUGsAaPEpyAlfZIpfwDA+qs=
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: QueueSharedKeyAuthenticator:validate() Signature 1 matched.
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 verbose: DeserializerMiddleware: Start deserializing...
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"b71aeedb-f75e-47f6-927a-b89bebe2f1ac"},"comp":"metadata","version":"2018-11-09"}
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified queue does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified queue does not exist. ErrorHTTPHeaders={"x-ms-error-code":"QueueNotFound","x-ms-request-id":"f1b9be3c-884c-425f-9fb2-89a67eb3a5a1","x-ms-version":"2021-04-10"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>QueueNotFound</Code>\n  <Message>The specified queue does not exist.\nRequestId:f1b9be3c-884c-425f-9fb2-89a67eb3a5a1\nTime:2022-05-12T03:51:19.009Z</Message>\n</Error>" ErrorStack="StorageError: The specified queue does not exist.\n    at Function.getQueueNotFound (****\\AppData\\Roaming\\npm\\node_modules\\azurite\\dist\\src\\queue\\errors\\StorageErrorFactory.js:107:16)\n    at LokiQueueMetadataStore.getQueue (****\\AppData\\Roaming\\npm\\node_modules\\azurite\\dist\\src\\queue\\persistence\\LokiQueueMetadataStore.js:230:49)\n    at QueueHandler.getProperties (****\\AppData\\Roaming\\npm\\node_modules\\azurite\\dist\\src\\queue\\handlers\\QueueHandler.js:81:48)\n    at ****\\AppData\\Roaming\\npm\\node_modules\\azurite\\dist\\src\\queue\\generated\\middleware\\HandlerMiddlewareFactory.js:58:18\n    at ****\\AppData\\Roaming\\npm\\node_modules\\azurite\\dist\\src\\queue\\generated\\ExpressMiddlewareFactory.js:77:63\n    at Layer.handle [as handle_request] (****\\AppData\\Roaming\\npm\\node_modules\\azurite\\node_modules\\express\\lib\\router\\layer.js:95:5)\n    at trim_prefix (****\\AppData\\Roaming\\npm\\node_modules\\azurite\\node_modules\\express\\lib\\router\\index.js:323:13)\n    at ****\\AppData\\Roaming\\npm\\node_modules\\azurite\\node_modules\\express\\lib\\router\\index.js:284:7\n    at Function.process_params (****\\Roaming\\npm\\node_modules\\azurite\\node_modules\\express\\lib\\router\\index.js:341:12)\n    at next (****AppData\\Roaming\\npm\\node_modules\\azurite\\node_modules\\express\\lib\\router\\index.js:275:10)"
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: Set HTTP code: 404
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: Set HTTP status message: The specified queue does not exist.
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=QueueNotFound
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=f1b9be3c-884c-425f-9fb2-89a67eb3a5a1
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: Set HTTP Header: x-ms-version=2021-04-10
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: Set content type: application/xml
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>QueueNotFound</Code>\n  <Message>The specified queue does not exist.\nRequestId:f1b9be3c-884c-425f-9fb2-89a67eb3a5a1\nTime:2022-05-12T03:51:19.009Z</Message>\n</Error>"
2022-05-12T03:51:19.009Z f1b9be3c-884c-425f-9fb2-89a67eb3a5a1 info: EndMiddleware: End response. TotalTimeInMS=1 StatusCode=404 StatusMessage=The specified queue does not exist. Headers={"server":"Azurite-Queue/3.16.0","x-ms-error-code":"QueueNotFound","x-ms-request-id":"f1b9be3c-884c-425f-9fb2-89a67eb3a5a1","x-ms-version":"2021-04-10","content-type":"application/xml"}

Steps to reproduce the issue?

No idea

Have you found a mitigation/solution?

Delete the entire storage in appdata/local/temp/azurite

blueww commented 2 years ago

@LukeBolly Thanks for raising the issue!

For missing of "\AppData\Local\Temp\Azuriteblobstorage\1ac1c0fa-fe17-4844-b192-f68fdc877e22" is weird, we may need a full debug.log to further troubleshoot. Would you please share the debug from you start azurite on a new folder and to the issue happen? And please make sure the account to run Azurite has full access like rw to the folder and its subfolders.

Besides that, Queue 404 is different and seems by design when the queue not created.

ADH-LukeBollam commented 2 years ago

Hi @blueww I still seem to be running into this issue. The full debug log is 350MB so I can't attach it here, can you give me a specific region to search for (such as where the storage might be recreated) and I'll grab the region for you

blueww commented 2 years ago

@LukeBolly For the queue 404, you might can search "Operation=Queue_Create" and "Operation=Queue_Delete", to make sure the queue is already created and not deleted before you run the GetProperties request.

For the other error, it might because you don't have full r/w access to the workspace folder. Do you run Azurite with Admin access, or can you make sure you have full access to the workspace of Azurite. If you run Azurite with admin credential, will the issue still repro?

ADH-LukeBollam commented 2 years ago

I don't manually run Azurite, Visual Studio starts it automatically on launch. I have full access to the folder because often it will work fine for days/weeks at a time. I searched for Queue_Delete but there are no such calls in the entire log. Something else must be deleting the file.

I have multiple Queue_Create calls, I suppose from the _queueClient.CreateIfNotExists(); which is called whenever the service tries to add another item to the queue.

blueww commented 2 years ago

@LukeBolly For "Operation=Queue_Create", is there a queue create operation for queue with name "import-jobs-poison" (you should can get the name from request Uri), and is it successful?

If you start Azurite (or Visual Studio) with admin, will the issue repro? Besides that, is there any other process on your computer can access the files in workspace?

ADH-LukeBollam commented 2 years ago

Here is the creation request for import-jobs-poison.

2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: QueueStorageContextMiddleware: RequestMethod=PUT RequestURL=http://127.0.0.1/devstoreaccount1/recording-import-jobs-poison RequestHeaders:{"host":"127.0.0.1:10001","x-ms-version":"2018-11-09","accept":"application/xml","x-ms-client-request-id":"9c14c7d7-8e45-4b55-9917-15831c787c87","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Storage.Queues/12.8.0 (.NET Core 3.1.28; Microsoft Windows 10.0.19043)","x-ms-date":"Thu, 15 Sep 2022 02:13:30 GMT","authorization":"SharedKey devstoreaccount1:2iZlQuM1kWXgWbfFTjGrI3J6qjeyLt61qJxrWJreY/E=","content-length":"0"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: QueueStorageContextMiddleware: Account=devstoreaccount1 Queue=recording-import-jobs-poison Message=undefined MessageId=undefined
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 verbose: DispatchMiddleware: Dispatching request...
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: DispatchMiddleware: Operation=Queue_Create
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: QueueSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: QueueSharedKeyAuthenticator:validate() [STRING TO SIGN]:"PUT\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:9c14c7d7-8e45-4b55-9917-15831c787c87\nx-ms-date:Thu, 15 Sep 2022 02:13:30 GMT\nx-ms-return-client-request-id:true\nx-ms-version:2018-11-09\n/devstoreaccount1/devstoreaccount1/recording-import-jobs-poison"
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: QueueSharedKeyAuthenticator:validate() Calculated authentication header based on key1: devstoreaccount1:2iZlQuM1kWXgWbfFTjGrI3J6qjeyLt61qJxrWJreY/E=
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: QueueSharedKeyAuthenticator:validate() Signature 1 matched.
2022-09-15T02:13:30.423Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 verbose: DeserializerMiddleware: Start deserializing...
2022-09-15T02:13:30.424Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: HandlerMiddleware: DeserializedParameters={"options":{"metadata":{},"requestId":"9c14c7d7-8e45-4b55-9917-15831c787c87"},"version":"2018-11-09"}
2022-09-15T02:13:30.424Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 verbose: SerializerMiddleware: Start serializing...
2022-09-15T02:13:30.424Z c9e23d40-3926-44ee-85a9-7ae1274a2a77 info: EndMiddleware: End response. TotalTimeInMS=1 StatusCode=201 StatusMessage=undefined Headers={"server":"Azurite-Queue/3.16.0","x-ms-client-request-id":"9c14c7d7-8e45-4b55-9917-15831c787c87","x-ms-request-id":"c9e23d40-3926-44ee-85a9-7ae1274a2a77","x-ms-version":"2021-04-10","date":"Thu, 15 Sep 2022 02:13:30 GMT"}

I don't have any other processes that I know of that touch the Azurite files. I can run VS as admin, but as I said it's intermittent for me so sometimes it takes a few days for the files to disappear.

steun86 commented 1 year ago

I just had the same thing happening to my local Azurite. I could see the files, but when I try to download a file it stays stuck in the transferring state in Azure Data Explorer. When I try to download the blob from my code, I receive an error: 500 (internal server error)

In my debug.log I also see that Azurite is trying to access a container that doesn't exist

2022-10-24T15:53:47.011Z 2ca7cc30-ca0a-4dfd-b1b9-eceaebc120be error: ErrorMiddleware: ErrorName=Error ErrorMessage=ENOENT: no such file or directory, open 'C:\Users\****\AppData\Local\Temp\Azurite\__blobstorage__\8fab0f8c-35da-45d5-addd-979555fd95ed' ErrorStack="Error: ENOENT: no such file or directory, open 'C:\\Users\\****\\AppData\\Local\\Temp\\Azurite\\__blobstorage__\\8fab0f8c-35da-45d5-addd-979555fd95ed'"

In our project we used the old, deprecated, azure storage emulator. We switched to Azurite 2 months ago and I assume it's related to this. If I remember correctly, after the switch I retained all my old containers.

blueww commented 1 year ago

@steun86

Thanks for reporting this issue! If you start Azurite (or Visual Studio) with admin, will the issue repro?

For "Azurite is trying to access a container that doesn't exist", do you mean Azurite try to access a local file not exist (as you log show), or a blob container not exist in Azurite?

steun86 commented 1 year ago

@blueww

@steun86

Thanks for reporting this issue! If you start Azurite (or Visual Studio) with admin, will the issue repro?

For "Azurite is trying to access a container that doesn't exist", do you mean Azurite try to access a local file not exist (as you log show), or a blob container not exist in Azurite?

To be able to continue with my work I deleted all files from \AppData\Local\Temp\Azurite. So I can't check if running with admin would solve the issue.

And for your second question. The actual local file didn't exist.

Sorry that this isn't so helpful. If I am able to reproduce the problem I will report back.

DocGreenRob commented 1 year ago

VS 2022 Enterprise. Created new Durable Function. F5, and ran into this issue.

2022-11-19T21:29:28.617Z 72d780e0-4bb1-40bc-9549-e98a3652d345 error: ErrorMiddleware: ErrorName=Error ErrorMessage=ENOENT: no such file or directory, open 'C:\Users\rober\AppData\Local\Temp\Azurite\__blobstorage__\2ef699ba-4ada-443a-81f4-63b6e58aa48f' ErrorStack="Error: ENOENT: no such file or directory, open 'C:\\Users\\rober\\AppData\\Local\\Temp\\Azurite\\__blobstorage__\\2ef699ba-4ada-443a-81f4-63b6e58aa48f'"

more logs ...

2022-11-19T21:29:15.293Z add7b3ad-4e7c-443d-97e3-c441890fe1b5 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"add7b3ad-4e7c-443d-97e3-c441890fe1b5"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:add7b3ad-4e7c-443d-97e3-c441890fe1b5\nTime:2022-11-19T21:29:15.293Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T21:29:15.294Z add7b3ad-4e7c-443d-97e3-c441890fe1b5 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T21:29:15.294Z add7b3ad-4e7c-443d-97e3-c441890fe1b5 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T21:29:15.294Z add7b3ad-4e7c-443d-97e3-c441890fe1b5 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T21:29:15.294Z add7b3ad-4e7c-443d-97e3-c441890fe1b5 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=add7b3ad-4e7c-443d-97e3-c441890fe1b5
2022-11-19T21:29:15.294Z add7b3ad-4e7c-443d-97e3-c441890fe1b5 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:add7b3ad-4e7c-443d-97e3-c441890fe1b5\nTime:2022-11-19T21:29:15.293Z</Message>\n</Error>"
2022-11-19T21:29:15.294Z add7b3ad-4e7c-443d-97e3-c441890fe1b5 info: EndMiddleware: End response. TotalTimeInMS=3 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"add7b3ad-4e7c-443d-97e3-c441890fe1b5"}
2022-11-19T21:29:15.426Z 7a14882f-8eca-462f-a69b-f18241702837 info: BlobStorageContextMiddleware: RequestMethod=PUT RequestURL=http://127.0.0.1/devstoreaccount1/azure-webjobs-secrets/laptop8vdhlm0d-510834381/host.json RequestHeaders:{"host":"127.0.0.1:10000","x-ms-blob-type":"BlockBlob","if-none-match":"*","x-ms-version":"2021-08-06","accept":"application/xml","x-ms-client-request-id":"7544c518-3da7-4ef4-9784-c7c4e350b673","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Storage.Blobs/12.13.0 (.NET 6.0.10; Microsoft Windows 10.0.22000)","x-ms-date":"Sat, 19 Nov 2022 21:29:15 GMT","authorization":"SharedKey devstoreaccount1:Y/76/bjaOKVqZq2JCTVISgQw6VaZdS1A8juMTOVqYr0=","traceparent":"00-9bcaa792948d92992e60e4de77e60c31-8384533292f8ff8e-00","content-length":"474","content-

but in VS Code, everything seems to be ok

image

however, I just arbitrarly right clicked on one of them ...

image

and noticed this message:

image

maybe this is related? (this is my first time working with Durable Functions and Azure Storage)

here are some logs... (few hundred lines)

2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:2495a39d-ff4c-4684-8a18-f8ae4e239e36\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:WhJUSWs9BqJ+HM3uzACPp/R0ewfsfY1k2ioqxs4/VnU=
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.521Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"2495a39d-ff4c-4684-8a18-f8ae4e239e36","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.522Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.522Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"8047216a-482d-4c58-a8dd-1d0dd7df7d67"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:8047216a-482d-4c58-a8dd-1d0dd7df7d67\nTime:2022-11-19T20:46:29.521Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.522Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.522Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.522Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.522Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=8047216a-482d-4c58-a8dd-1d0dd7df7d67
2022-11-19T20:46:29.522Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:8047216a-482d-4c58-a8dd-1d0dd7df7d67\nTime:2022-11-19T20:46:29.521Z</Message>\n</Error>"
2022-11-19T20:46:29.522Z 8047216a-482d-4c58-a8dd-1d0dd7df7d67 info: EndMiddleware: End response. TotalTimeInMS=2 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"8047216a-482d-4c58-a8dd-1d0dd7df7d67"}
2022-11-19T20:46:29.559Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"7a318d0a-9ead-420e-899f-1cdf85216602","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:s7xWokpV9M7DEZqy+QmUPbPp/Dode2gxp+g0RZ3Wk0s=","traceparent":"00-ea6789c4d997aae6cc1716e197ae5ff8-a35f7362aae80466-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.559Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.559Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:7a318d0a-9ead-420e-899f-1cdf85216602\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:s7xWokpV9M7DEZqy+QmUPbPp/Dode2gxp+g0RZ3Wk0s=
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.560Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"7a318d0a-9ead-420e-899f-1cdf85216602","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.561Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.561Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"8c8c679b-fa3b-4681-adc2-54ad3293efc3"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:8c8c679b-fa3b-4681-adc2-54ad3293efc3\nTime:2022-11-19T20:46:29.560Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.561Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.561Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.561Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.561Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=8c8c679b-fa3b-4681-adc2-54ad3293efc3
2022-11-19T20:46:29.561Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:8c8c679b-fa3b-4681-adc2-54ad3293efc3\nTime:2022-11-19T20:46:29.560Z</Message>\n</Error>"
2022-11-19T20:46:29.561Z 8c8c679b-fa3b-4681-adc2-54ad3293efc3 info: EndMiddleware: End response. TotalTimeInMS=2 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"8c8c679b-fa3b-4681-adc2-54ad3293efc3"}
2022-11-19T20:46:29.598Z cb909980-4c37-4c30-905b-ed1a18f1827d info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"1e559819-ee57-4c10-ac2f-bfd8ffa5cafc","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:w+cnz2Yoi7h8tgWHeV7XW5q12aWIaZmgsfgPGWNf6yM=","traceparent":"00-b885d364752de98909393c03d6d7a5ed-ce471499903fa91a-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.598Z cb909980-4c37-4c30-905b-ed1a18f1827d info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.598Z cb909980-4c37-4c30-905b-ed1a18f1827d verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.598Z cb909980-4c37-4c30-905b-ed1a18f1827d info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.598Z cb909980-4c37-4c30-905b-ed1a18f1827d verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.598Z cb909980-4c37-4c30-905b-ed1a18f1827d info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.598Z cb909980-4c37-4c30-905b-ed1a18f1827d debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.598Z cb909980-4c37-4c30-905b-ed1a18f1827d debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:1e559819-ee57-4c10-ac2f-bfd8ffa5cafc\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:w+cnz2Yoi7h8tgWHeV7XW5q12aWIaZmgsfgPGWNf6yM=
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"1e559819-ee57-4c10-ac2f-bfd8ffa5cafc","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"cb909980-4c37-4c30-905b-ed1a18f1827d"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:cb909980-4c37-4c30-905b-ed1a18f1827d\nTime:2022-11-19T20:46:29.599Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=cb909980-4c37-4c30-905b-ed1a18f1827d
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:cb909980-4c37-4c30-905b-ed1a18f1827d\nTime:2022-11-19T20:46:29.599Z</Message>\n</Error>"
2022-11-19T20:46:29.599Z cb909980-4c37-4c30-905b-ed1a18f1827d info: EndMiddleware: End response. TotalTimeInMS=1 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"cb909980-4c37-4c30-905b-ed1a18f1827d"}
2022-11-19T20:46:29.636Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"e6ee7d11-6c40-46b4-934e-36be7f95517c","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:k/9rV0tDDsWIv5zWHPTshSZZ8vq++5I1RPylMD6nhHY=","traceparent":"00-eff81cbabdff0209c9cfe7f664bfb7d7-8c9f24d14719fd96-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.636Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.636Z 6501ece1-c182-404f-8e21-2424a052f6e8 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:e6ee740-46b4-934e-36be7f95517c\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:k/9rV0tDDsWIv5zWHPTshSZZ8vq++5I1RPylMD6nhHY=
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"e6ee7d11-6c40-46b4-934e-36be7f95517c","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"6501ece1-c182-404f-8e21-2424a052f6e8"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:6501ece1-c182-404f-8e21-2424a052f6e8\nTime:2022-11-19T20:46:29.637Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.637Z 6501ece1-c182-404f-8e21-2424a052f6e8 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.638Z 6501ece1-c182-404f-8e21-2424a052f6e8 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.638Z 6501ece1-c182-404f-8e21-2424a052f6e8 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.638Z 6501ece1-c182-404f-8e21-2424a052f6e8 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=6501ece1-c182-404f-8e21-2424a052f6e8
2022-11-19T20:46:29.638Z 6501ece1-c182-404f-8e21-2424a052f6e8 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:6501ece1-c182-404f-8e21-2424a052f6e8\nTime:2022-11-19T20:46:29.637Z</Message>\n</Error>"
2022-11-19T20:46:29.638Z 6501ece1-c182-404f-8e21-2424a052f6e8 info: EndMiddleware: End response. TotalTimeInMS=2 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"6501ece1-c182-404f-8e21-2424a052f6e8"}
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"2ad4b055-ceda-45f9-9a0f-f3a4977b91fe","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:8Mjkdo0VurDXHM56PnGHrWgHCEI9/15ncsrKxMNDLsA=","traceparent":"00-8b76af28fa7f561469505b5f638af1ca-116f4e00366e3a5a-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:2ad4b055-ceda-45f9-9a0f-f3a4977b91fe\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:8Mjkdo0VurDXHM56PnGHrWgHCEI9/15ncsrKxMNDLsA=
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.675Z a81926d5-be45-4b65-8f2b-1eeb727680b3 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"2ad4b055-ceda-45f9-9a0f-f3a4977b91fe","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"a81926d5-be45-4b65-8f2b-1eeb727680b3"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:a81926d5-be45-4b65-8f2b-1eeb727680b3\nTime:2022-11-19T20:46:29.676Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=a81926d5-be45-4b65-8f2b-1eeb727680b3
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:a81926d5-be45-4b65-8f2b-1eeb727680b3\nTime:2022-11-19T20:46:29.676Z</Message>\n</Error>"
2022-11-19T20:46:29.676Z a81926d5-be45-4b65-8f2b-1eeb727680b3 info: EndMiddleware: End response. TotalTimeInMS=1 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"a81926d5-be45-4b65-8f2b-1eeb727680b3"}
2022-11-19T20:46:29.714Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"5bd9bd1e-8485-4e2e-80b7-6005c18e5925","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:rJftR//Kuw8a1twhUaliJ3er8WSbV0U9tk/WZZHUC1w=","traceparent":"00-4fde57cd53dd8cb82a0f63d49382151f-dcd4965c2b504788-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.714Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.714Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.714Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.714Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.714Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:5bd9bd1e-8485-4e2e-80b7-6005c18e5925\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:rJftR//Kuw8a1twhUaliJ3er8WSbV0U9tk/WZZHUC1w=
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"5bd9bd1e-8485-4e2e-80b7-6005c18e5925","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"e9ab7da3-9329-4ac2-8ade-e6a178ac090b"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:e9ab7da3-9329-4ac2-8ade-e6a178ac090b\nTime:2022-11-19T20:46:29.715Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=e9ab7da3-9329-4ac2-8ade-e6a178ac090b
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:e9ab7da3-9329-4ac2-8ade-e6a178ac090b\nTime:2022-11-19T20:46:29.715Z</Message>\n</Error>"
2022-11-19T20:46:29.715Z e9ab7da3-9329-4ac2-8ade-e6a178ac090b info: EndMiddleware: End response. TotalTimeInMS=1 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"e9ab7da3-9329-4ac2-8ade-e6a178ac090b"}
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"41c5c160-a462-4e89-b890-72230cee304f","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:9QKv+cSK0hycULEg4/uIMuwhDI7GhU72eIux0x/vHbQ=","traceparent":"00-c874a83e627bfb4d0885a9dd1014a804-ad31392a5b7f8a53-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.752Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:41c5c160-a462-4e89-b890-72230cee304f\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:9QKv+cSK0hycULEg4/uIMuwhDI7GhU72eIux0x/vHbQ=
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"41c5c160-a462-4e89-b890-72230cee304f","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93\nTime:2022-11-19T20:46:29.753Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93\nTime:2022-11-19T20:46:29.753Z</Message>\n</Error>"
2022-11-19T20:46:29.753Z ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93 info: EndMiddleware: End response. TotalTimeInMS=1 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"ac5ae4be-d2f0-46f8-b6f4-bf8ebf85da93"}
2022-11-19T20:46:29.790Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"7b2bdd59-3de1-4c2a-93f9-58b809151980","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:fz0BG9w+wTp75esGX3ErqolWo0ZFNmLIeDHbglVjbmg=","traceparent":"00-bfa27974b20060a91c5fafe6a7fd3450-b94e362d75254cd9-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.790Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.790Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:7b2bdd59-3de1-4c2a-93f9-58b809151980\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:fz0BG9w+wTp75esGX3ErqolWo0ZFNmLIeDHbglVjbmg=
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"7b2bdd59-3de1-4c2a-93f9-58b809151980","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.791Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.792Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"85544ca4-fd33-44f2-a04f-5fa5ceaccc26"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:85544ca4-fd33-44f2-a04f-5fa5ceaccc26\nTime:2022-11-19T20:46:29.791Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.792Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.792Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.792Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.792Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=85544ca4-fd33-44f2-a04f-5fa5ceaccc26
2022-11-19T20:46:29.792Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:85544ca4-fd33-44f2-a04f-5fa5ceaccc26\nTime:2022-11-19T20:46:29.791Z</Message>\n</Error>"
2022-11-19T20:46:29.792Z 85544ca4-fd33-44f2-a04f-5fa5ceaccc26 info: EndMiddleware: End response. TotalTimeInMS=2 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"85544ca4-fd33-44f2-a04f-5fa5ceaccc26"}
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"5eda8652-a5c4-418f-8795-ee0574371995","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:8fcBJkAXtrjzYXw+QGPX5zEl42wNTluha1FU8JIMZFw=","traceparent":"00-17d200d8ff5c5d457568f0ff3a3f5811-b257477571431d71-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.831Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:5eda8652-a5c4-418f-8795-ee0574371995\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:8fcBJkAXtrjzYXw+QGPX5zEl42wNTluha1FU8JIMZFw=
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"5eda8652-a5c4-418f-8795-ee0574371995","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"9740a3ff-6ff2-4570-a658-dec82ddd12b9"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:9740a3ff-6ff2-4570-a658-dec82ddd12b9\nTime:2022-11-19T20:46:29.832Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=9740a3ff-6ff2-4570-a658-dec82ddd12b9
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:9740a3ff-6ff2-4570-a658-dec82ddd12b9\nTime:2022-11-19T20:46:29.832Z</Message>\n</Error>"
2022-11-19T20:46:29.832Z 9740a3ff-6ff2-4570-a658-dec82ddd12b9 info: EndMiddleware: End response. TotalTimeInMS=1 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"9740a3ff-6ff2-4570-a658-dec82ddd12b9"}
2022-11-19T20:46:29.868Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"ebb031e7-2eaa-4f8f-9fc8-6dc4ba1310b6","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:JXvSlZLdPiJoOjSvR2l8jdLpvInp7fZKoz59T2rcxrQ=","traceparent":"00-574be6e6821b19188b7e8b215709a255-2c2c3bcdbd6ffe2d-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.868Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.868Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:ebb031e7-2eaa-4f8f-9fc8-6dc4ba1310b6\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:JXvSlZLdPiJoOjSvR2l8jdLpvInp7fZKoz59T2rcxrQ=
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"ebb031e7-2eaa-4f8f-9fc8-6dc4ba1310b6","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"fe61d69d-bc8f-4c71-864a-0105afa82eb9"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:fe61d69d-bc8f-4c71-864a-0105afa82eb9\nTime:2022-11-19T20:46:29.869Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.869Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=fe61d69d-bc8f-4c71-864a-0105afa82eb9
2022-11-19T20:46:29.870Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:fe61d69d-bc8f-4c71-864a-0105afa82eb9\nTime:2022-11-19T20:46:29.869Z</Message>\n</Error>"
2022-11-19T20:46:29.870Z fe61d69d-bc8f-4c71-864a-0105afa82eb9 info: EndMiddleware: End response. TotalTimeInMS=2 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"fe61d69d-bc8f-4c71-864a-0105afa82eb9"}
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: BlobStorageContextMiddleware: RequestMethod=HEAD RequestURL=http://127.0.0.1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo RequestHeaders:{"host":"127.0.0.1:10000","x-ms-client-request-id":"22b76506-fa1f-4262-b4e0-a64f072875b9","user-agent":"Azure-Storage/9.3.1 (.NET Core)","x-ms-version":"2018-03-28","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:zyjTaKr7FWtXy93h/5yQytw4hBqrSLZBxwj5rI8CEww=","traceparent":"00-008d83b0395c9d571cefbada65ad3be1-1e193bedba8aed00-00"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: DispatchMiddleware: Operation=Blob_GetProperties
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: testhubname-applease, blob: testhubname-appleaseinfo
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container testhubname-applease
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"HEAD\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:22b76506-fa1f-4262-b4e0-a64f072875b9\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-version:2018-03-28\n/devstoreaccount1/devstoreaccount1/testhubname-applease/testhubname-appleaseinfo"
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:zyjTaKr7FWtXy93h/5yQytw4hBqrSLZBxwj5rI8CEww=
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.907Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"22b76506-fa1f-4262-b4e0-a64f072875b9","leaseAccessConditions":{},"cpkInfo":{},"modifiedAccessConditions":{}},"version":"2018-03-28"}
2022-11-19T20:46:29.908Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 error: ErrorMiddleware: Received a MiddlewareError, fill error information to HTTP response
2022-11-19T20:46:29.908Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 error: ErrorMiddleware: ErrorName=StorageError ErrorMessage=The specified blob does not exist.  ErrorHTTPStatusCode=404 ErrorHTTPStatusMessage=The specified blob does not exist. ErrorHTTPHeaders={"x-ms-error-code":"BlobNotFound","x-ms-request-id":"ab24bba8-4d0c-42bd-bcaa-9833ac426577"} ErrorHTTPBody="<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:ab24bba8-4d0c-42bd-bcaa-9833ac426577\nTime:2022-11-19T20:46:29.908Z</Message>\n</Error>" ErrorStack="StorageError: The specified blob does not exist.\n    at Function.getBlobNotFound (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\errors\\StorageErrorFactory.js:29:16)\n    at LokiBlobMetadataStore.getBlobProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\persistence\\LokiBlobMetadataStore.js:805:49)\n    at runMicrotasks (<anonymous>)\n    at processTicksAndRejections (internal/process/task_queues.js:95:5)\n    at async BlobHandler.getProperties (C:\\snapshot\\_azure_azurite\\dist\\src\\blob\\handlers\\BlobHandler.js:80:21)"
2022-11-19T20:46:29.908Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 error: ErrorMiddleware: Set HTTP code: 404
2022-11-19T20:46:29.908Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 error: ErrorMiddleware: Set HTTP status message: The specified blob does not exist.
2022-11-19T20:46:29.908Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 error: ErrorMiddleware: Set HTTP Header: x-ms-error-code=BlobNotFound
2022-11-19T20:46:29.908Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 error: ErrorMiddleware: Set HTTP Header: x-ms-request-id=ab24bba8-4d0c-42bd-bcaa-9833ac426577
2022-11-19T20:46:29.908Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 error: ErrorMiddleware: Set HTTP body: "<?xml version=\"1.0\" encoding=\"UTF-8\" standalone=\"yes\"?>\n<Error>\n  <Code>BlobNotFound</Code>\n  <Message>The specified blob does not exist.\nRequestId:ab24bba8-4d0c-42bd-bcaa-9833ac426577\nTime:2022-11-19T20:46:29.908Z</Message>\n</Error>"
2022-11-19T20:46:29.908Z ab24bba8-4d0c-42bd-bcaa-9833ac426577 info: EndMiddleware: End response. TotalTimeInMS=1 StatusCode=404 StatusMessage=The specified blob does not exist. Headers={"server":"Azurite-Blob/3.18.0","x-ms-error-code":"BlobNotFound","x-ms-request-id":"ab24bba8-4d0c-42bd-bcaa-9833ac426577"}
2022-11-19T20:46:29.941Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: BlobStorageContextMiddleware: RequestMethod=PUT RequestURL=http://127.0.0.1/devstoreaccount1/azure-webjobs-hosts/locks/laptop8vdhlm0d-510834381/host?comp=lease RequestHeaders:{"host":"127.0.0.1:10000","x-ms-lease-action":"renew","x-ms-lease-id":"000000000000000000000000AA169013","x-ms-version":"2021-08-06","accept":"application/xml","x-ms-client-request-id":"60c7af63-a6e0-442d-978e-717d25525973","x-ms-return-client-request-id":"true","user-agent":"azsdk-net-Storage.Blobs/12.13.0 (.NET 6.0.10; Microsoft Windows 10.0.22000)","x-ms-date":"Sat, 19 Nov 2022 20:46:29 GMT","authorization":"SharedKey devstoreaccount1:wB+HHQig4feDYKTRTrMzBUqds4Hdu+DkSHBDnQV+GlM=","traceparent":"00-c4786460a5b4c581f8bb458fe642a3ef-84f9b4fb5963cb5f-00","content-length":"0"} ClientIP=127.0.0.1 Protocol=http HTTPVersion=1.1
2022-11-19T20:46:29.941Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: BlobStorageContextMiddleware: Account=devstoreaccount1 Container=azure-webjobs-hosts Blob=locks/laptop8vdhlm0d-510834381/host
2022-11-19T20:46:29.941Z 2a049d3c-f4fc-498a-aa14-39063f26f445 verbose: DispatchMiddleware: Dispatching request...
2022-11-19T20:46:29.941Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: DispatchMiddleware: Operation=Blob_RenewLease
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 verbose: AuthenticationMiddlewareFactory:createAuthenticationMiddleware() Validating authentications.
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: PublicAccessAuthenticator:validate() Start validation against public access.
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 debug: PublicAccessAuthenticator:validate() Getting account properties...
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 debug: PublicAccessAuthenticator:validate() Retrieved account name from context: devstoreaccount1, container: azure-webjobs-hosts, blob: locks/laptop8vdhlm0d-510834381/host
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 debug: PublicAccessAuthenticator:validate() Skip public access authentication. Cannot get public access type for container azure-webjobs-hosts
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: BlobSharedKeyAuthenticator:validate() Start validation against account shared key authentication.
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: BlobSharedKeyAuthenticator:validate() [STRING TO SIGN]:"PUT\n\n\n\n\n\n\n\n\n\n\n\nx-ms-client-request-id:60c7af63-a6e0-442d-978e-717d25525973\nx-ms-date:Sat, 19 Nov 2022 20:46:29 GMT\nx-ms-lease-action:renew\nx-ms-lease-id:000000000000000000000000AA169013\nx-ms-return-client-request-id:true\nx-ms-version:2021-08-06\n/devstoreaccount1/devstoreaccount1/azure-webjobs-hosts/locks/laptop8vdhlm0d-510834381/host\ncomp:lease"
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: BlobSharedKeyAuthenticator:validate() Calculated authentication header based on key1: SharedKey devstoreaccount1:wB+HHQig4feDYKTRTrMzBUqds4Hdu+DkSHBDnQV+GlM=
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: BlobSharedKeyAuthenticator:validate() Signature 1 matched.
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 verbose: DeserializerMiddleware: Start deserializing...
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 info: HandlerMiddleware: DeserializedParameters={"options":{"requestId":"60c7af63-a6e0-442d-978e-717d25525973","modifiedAccessConditions":{}},"comp":"lease","leaseId":"000000000000000000000000AA169013","version":"2021-08-06","action":"renew"}
2022-11-19T20:46:29.942Z 2a049d3c-f4fc-498a-aa14-39063f26f445 verbose: SerializerMiddleware: Start serializing...

(note, new to Durable Funcs and all the Azure Storage stuff but I guess its just common sense but this is my first time working with it)

blueww commented 1 year ago

@DocGreenRob

For the above picture, not sure which vs extension are you using. If you are using storage explorer, how do you add Azurite account to Storage explorer? The error "Cannot retrieve storage account id for an attached account." looks more like a client side error of can't retrieve saved storage account id from client saved config. There's a similar issue for storage explorer, but seems no conclusion for this issue.

For the above debug log, it looks failed 11 times on "Blob_GetProperties" on same blob "Account=devstoreaccount1 Container=testhubname-applease Blob=testhubname-appleaseinfo" with 404 (The specified blob does not exist) error. The error might can caused by the blob/container not exist. Since we don't see the log to create the blob/container, so not sure if you have created them before Get properties on the blob.

Besides that, from the picture, the "Cannot retrieve storage account id for an attached account." error happens when you try to access a Queue, but the debug log are all for blob request. so looks they are not aligned.

BTW, for you reference, there's a similar issue when upgrade from VS2019 to VS2022, and resolved by clearing out that temp directory completely reset VS2022 : https://github.com/Azure/Azurite/issues/1447#issuecomment-1309222760 Hope that's helpful for you.

ADH-LukeBollam commented 1 year ago

My azurite broke again today, I noticed some logs in the Service Dependencies in visual studio that might be useful. It got a 409 trying to put something in a container, before the 500 errors started

****.FunctionApp: azurite.cmd --location "***" --debug "***"
****.FunctionApp: Azurite Blob service is starting at http://127.0.0.1:10000
****.FunctionApp: Azurite Blob service is successfully listening at http://127.0.0.1:10000
****.FunctionApp: Azurite Queue service is starting at http://127.0.0.1:10001
****.FunctionApp: Azurite Queue service is successfully listening at http://127.0.0.1:10001
****.FunctionApp: Azurite Table service is starting at http://127.0.0.1:10002
****.FunctionApp: Azurite Table service is successfully listening at http://127.0.0.1:10002
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:37 +0000] "GET /****?comp=metadata HTTP/1.1" 200 -
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:37 +0000] "GET /****/messages?numofmessages=1&visibilitytimeout=600 HTTP/1.1" 200 -
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:37 +0000] "GET /****/messages?numofmessages=1&visibilitytimeout=600 HTTP/1.1" 200 -
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:41 +0000] "PUT /****/host?comp=lease HTTP/1.1" 201 -
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:41 +0000] "HEAD /****/host HTTP/1.1" 200 0
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:41 +0000] "PUT /****/host?comp=metadata HTTP/1.1" 200 -
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:42 +0000] "GET /****/messages?numofmessages=1&visibilitytimeout=600 HTTP/1.1" 200 -
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:43 +0000] "PUT /****?restype=container HTTP/1.1" 409 -
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:43 +0000] "GET /****/keys.xml HTTP/1.1" 500 952
****.FunctionApp: 127.0.0.1 - - [25/Nov/2022:01:02:43 +0000] "GET /****/keys.xml HTTP/1.1" 500 952
blueww commented 1 year ago

@LukeBolly Thanks for the log! Could you please share the Azurite debug log for this case? We need to debug log to get more information to do further investigation.

ADH-LukeBollam commented 1 year ago

Ignore the 409, that's just our app behavior, we try to create a container and if it already exists then we get the resource instead. Azurite still broke though, so here is the log from the start of the day (it was working until the end of yesterday) until the first 500 of the day. You'll see the 409 when we try to create a container that already exists, but then when we try to get it, we get a 500 error because it doesn't actually exist and it throws the ENOENT error you've seen earlier

errorlog25Nov22.txt

ADH-LukeBollam commented 1 year ago

If it makes any difference, yesterday I put my computer to sleep instead of turning it off like I usually do.

ADH-LukeBollam commented 1 year ago

I've just found that Windows has a service called Storage Sense which will automatically delete files from AppData\Local\Temp when storage gets low. It's possible this is happening to me because it's turned on, but I can't actually tell because it doesn't log any useful info and the description is quite vague.

https://answers.microsoft.com/en-us/windows/forum/all/storage-sense-configuration-for-deleting-temporary/321616d1-e6a7-413a-8246-28f88f5ecc4e

Maybe storing the data into temp isn't a good idea.

ADH-LukeBollam commented 1 year ago

@blueww just letting you know, I haven't had the issue since I disabled Storage Sense on the temp directory. This is a default Windows setting so I won't be the last person to be impacted by it, so you may want to change the Azurite directory out of the /temp folder.

It would also be nice to have it in C drive, or somewhere more accessible, because getting to temp is a bit of a pain and honestly a bit unexpected to store persistent data.

blueww commented 1 year ago

@LukeBolly Thanks so much for the detail investigation and updating!

This temp folder is actually not defined in Azurite itself, but by Visual studio when it starts Azurite. We will contact Visual studio team to see if can handle it better.

BTW, you can also raise the issue to Visual team directly: This doc has the details on how to report a VS feedback issue : https://docs.microsoft.com/en-us/visualstudio/ide/how-to-report-a-problem-with-visual-studio?view=vs-2022