Azure / azure-functions-python-library

Azure Functions Python SDK
MIT License
151 stars 63 forks source link

[BUG] Service Bus Session ID is not available to Function code #103

Open sidkri opened 2 years ago

sidkri commented 2 years ago

Investigative information

Please provide the following:

IcM: 283549053 has an impacted function app with relevant detail

Repro steps

  1. Create a Function App that triggers off a Service bus session enabled queue.
    Provide the steps required to reproduce the problem:

Expected behavior

Provide a description of the expected behavior.

Actual behavior

Provide a description of the actual behavior observed.
### Known workarounds ###### Provide a description of any known workarounds. Fetch the session id from the nested field in the message: msg.metadata["MessageSession"]["SessionId"] ### Contents of the requirements.txt file: ###### Provide the requirements.txt file to help us find out module related issues. N/A ### Related information ###### Provide any related information * Bindings used: Service Bus ```python def main(msg: func.ServiceBusMessage): logging.info('Python ServiceBus queue trigger processed message: %s', msg.get_body().decode('utf-8')) logging.info('Python msg.session_id - : %s', msg.metadata["MessageSession"]["SessionId"]) logging.info('Python msg.session_id1 - : %s', msg.session_id) ``` Output ```logs [2022-02-09T00:36:58.242Z] Python msg.session_id - : {12229E1-B37B-4D29-AA0A-E367906C206E} [2022-02-09T00:36:58.242Z] Python msg.session_id1 - : None ``` The [location where library sets session_id](https://github.com/Azure/azure-functions-python-library/blob/dev/azure/functions/servicebus.py#L274-L275). ```bash curl -H "Authorization: SharedAccessSignature sr=SERVICE_BUS.servicebus.windows.net%2FINPUT_QUEUE&sig=XXXXXX&se=YYY&skn=RootManageSharedAccessKey" \ -H 'BrokerProperties: {"SessionId": "{12229E1-B37B-4D29-AA0A-E367906C206E}"}' \ -H "Content-Type: application/json" \ -d "HelloWorld" \ -X POST -i "https://servicebus-test-vameru.servicebus.windows.net/myinputqueue/messages\?timeout\=60" HTTP/1.1 201 Created Transfer-Encoding: chunked Content-Type: application/xml; charset=utf-8 Server: Microsoft-HTTPAPI/2.0 Strict-Transport-Security: max-age=31536000 Date: Wed, 09 Feb 2022 00:36:57 GMT ``` The Complete Metadata ```json { "UserProperties": {}, "DeliveryCount": 1, "LockToken": "fc949e24-410f-4a78-853b-7b8ce125cb99", "MessageSession": { "LockedUntilUtc": "2022-02-08T22: 30: 52.33697Z", "SessionId": "{17729E1-B37B-4D29-AA0A-E367906C206E}", "RegisteredPlugins": [], "ReceiveMode": 0, "PrefetchCount": 0, "LastPeekedSequenceNumber": 0, "Path": "myinputqueue", "OperationTimeout": "00: 01: 00", "ServiceBusConnection": { "Endpoint": "sb://servicebus-test-vameru.servicebus.windows.net", "OperationTimeout": "00:01:00", "RetryPolicy": { "MinimalBackoff": "00:00:00", "MaximumBackoff": "00:00:30", "DeltaBackoff": "00:00:03", "MaxRetryCount": 5, "IsServerBusy": False, "ServerBusyExceptionMessage": None }, "TransportType": 0, "TokenProvider": {}, "IsClosedOrClosing": False }, "IsClosedOrClosing": False, "OwnsConnection": False, "ClientId": "MessageSession27myinputqueue_{17729E1-B37B-4D29-AA0A-E367906C206E}", "RetryPolicy": { "MinimalBackoff": "00:00:00", "MaximumBackoff": "00:00:30", "DeltaBackoff": "00:00:03", "MaxRetryCount": 5, "IsServerBusy": False, "ServerBusyExceptionMessage": None } }, "ContentType": "application/json", "SequenceNumber": 13, "MessageReceiver": { "LockedUntilUtc": "2022-02-08T22:30:52.33697Z", "SessionId": "{17729E1-B37B-4D29-AA0A-E367906C206E}", "RegisteredPlugins": [], "ReceiveMode": 0, "PrefetchCount": 0, "LastPeekedSequenceNumber": 0, "Path": "myinputqueue", "OperationTimeout": "00:01:00", "ServiceBusConnection": { "Endpoint": "sb://servicebus-test-vameru.servicebus.windows.net", "OperationTimeout": "00:01:00", "RetryPolicy": { "MinimalBackoff": "00:00:00", "MaximumBackoff": "00:00:30", "DeltaBackoff": "00:00:03", "MaxRetryCount": 5, "IsServerBusy": False, "ServerBusyExceptionMessage": None }, "TransportType": 0, "TokenProvider": {}, "IsClosedOrClosing": False }, "IsClosedOrClosing": False, "OwnsConnection": False, "ClientId": "MessageSession27myinputqueue_{17729E1-B37B-4D29-AA0A-E367906C206E}", "RetryPolicy": { "MinimalBackoff": "00:00:00", "MaximumBackoff": "00:00:30", "DeltaBackoff": "00:00:03", "MaxRetryCount": 5, "IsServerBusy": False, "ServerBusyExceptionMessage": None } }, "EnqueuedTimeUtc": "2022-02-08T22:22:19.292Z", "ExpiresAtUtc": "2022-02-22T22:22:19.292Z", "MessageId": "806c77a2924441fe855697d39647e096" } ```
sidkri commented 2 years ago

We should understand if this a regression and if so how it was introduced.

  1. Did the serialization logic change? Let's understand where the Service Bus Message's serialized structure (over grpc) is coming from. Does the SDK serialize the message or is the extension/functions host defining the structure during serialization.
  2. Did the deserialization logic in the python functions library change?
teebu commented 2 years ago

Seeing this as well. Using sample code provided here: https://docs.microsoft.com/en-us/azure/azure-functions/functions-bindings-service-bus-trigger?tabs=in-process%2Cextensionv5&pivots=programming-language-python

[2022-06-26T19:13:02.445Z] Trigger Details: MessageId: 79a448110d84468fa66184d80828a198, SequenceNumber: 3, DeliveryCount: 1, EnqueuedTimeUtc: 2022-06-26T19:13:03.5390000+00:00, LockedUntilUtc: 9999-12-31T23:59:59.9999999+00:00, SessionId: a
[2022-06-26T19:13:02.456Z] {
    "message_id": "79a448110d84468fa66184d80828a198",
    "body": "2",
    "content_type": null,
    "expiration_time": "2022-07-10 19:13:03.539000",
    "label": null,
    "partition_key": null,
    "reply_to": null,
    "reply_to_session_id": null,
    "scheduled_enqueue_time": null,
    "session_id": null,
    "time_to_live": null,
    "to": null,
    "user_properties": {},
    "metadata": {
        "MessageReceiver": {
            "SessionLockedUntil": "2022-06-26T19:13:33.5547459+00:00"
        },
        "MessageActions": {
            "SessionLockedUntil": "2022-06-26T19:13:33.5547459+00:00"
        },
        "MessageSession": {
            "SessionLockedUntil": "2022-06-26T19:13:33.5547459+00:00"
        },
        "DeliveryCount": 1,
        "LockToken": "6ec5c950-5ed9-49dc-b8bb-6f637054a0fc",
        "ExpiresAt": "2022-07-10T19:13:03.539+00:00",
        "ExpiresAtUtc": "2022-07-10T19:13:03.539",
        "SequenceNumber": 3,
        "ApplicationProperties": {},
        "SessionActions": {
            "SessionLockedUntil": "2022-06-26T19:13:33.5547459+00:00"
        },
        "EnqueuedTime": "2022-06-26T19:13:03.539+00:00",
        "MessageId": "79a448110d84468fa66184d80828a198",
        "UserProperties": {},
        "EnqueuedTimeUtc": "2022-06-26T19:13:03.539",
        "Client": {
            "FullyQualifiedNamespace": "test-function.servicebus.windows.net",
            "IsClosed": false,
            "TransportType": 0
        }
    }
}