[BUG] Session MaxAutoLockRenewalDuration and SessionIdleTimeout values causing queue starvation about azure-sdk-for-net HOT 10 OPEN

Thank you for your feedback. Tagging and routing to the team member best able to assist.

from azure-sdk-for-net.

@bramley-jetcharge, there was a bug in 7.17.2 that may be related to the issues you are facing. Can you try to repro on 7.17.3?

from azure-sdk-for-net.

Hi @bramley-jetcharge. Thank you for opening this issue and giving us the opportunity to assist. To help our team better understand your issue and the details of your scenario please provide a response to the question asked above or the information requested above. This will help us more accurately address your issue.

from azure-sdk-for-net.

Thanks, looks like you released 7.17.3 right after I started testing! It did fix issue 2, but I am still seeing issue 1:
MaxAutoLockRenewalDuration = TimeSpan.FromMinutes(6), SessionIdleTimeout = TimeSpan.FromMinutes(4), and sending messages every 31 seconds

After 6+ minutes, messages continue to be received on the same handler. The ProcessSessionMessageEventArgs.SessionLockedUntil time becomes negative. I left this run for an hour, the lock time never increased.

sample output:

17/02/2024 2:45:40 AM: SessionInitializingHandler egg
17/02/2024 2:45:40 AM: egg: Msg 0. Lag: 1.8969068s. Lock duration: 58.1191186s
17/02/2024 2:46:11 AM: egg: Msg 1. Lag: 1.6884163s. Lock duration: 27.2616091s
17/02/2024 2:46:42 AM: egg: Msg 2. Lag: 1.6716996s. Lock duration: 44.7163004s
17/02/2024 2:47:13 AM: egg: Msg 3. Lag: 1.6744682s. Lock duration: 13.6685318s
17/02/2024 2:47:44 AM: egg: Msg 4. Lag: 1.7002465s. Lock duration: 30.9367535s
17/02/2024 2:48:15 AM: egg: Msg 5. Lag: 1.6760181s. Lock duration: 48.2279819s
17/02/2024 2:48:46 AM: egg: Msg 6. Lag: 1.6731483s. Lock duration: 17.1618517s
17/02/2024 2:49:17 AM: egg: Msg 7. Lag: 1.6935753s. Lock duration: 34.5224247s
17/02/2024 2:49:48 AM: egg: Msg 8. Lag: 1.6969981s. Lock duration: 51.8180019s
17/02/2024 2:50:19 AM: egg: Msg 9. Lag: 1.6727394s. Lock duration: 20.7732606s
17/02/2024 2:50:50 AM: egg: Msg 10. Lag: 1.6940355s. Lock duration: 38.1409645s
17/02/2024 2:51:21 AM: egg: Msg 11. Lag: 1.7091079s. Lock duration: 55.4148921s
17/02/2024 2:51:52 AM: egg: Msg 12. Lag: 1.6725705s. Lock duration: 24.3744295s
17/02/2024 2:52:23 AM: egg: Msg 13. Lag: 1.6772244s. Lock duration: -6.6662244s
17/02/2024 2:52:55 AM: egg: Msg 14. Lag: 1.682253s. Lock duration: -37.721253s
17/02/2024 2:53:26 AM: egg: Msg 15. Lag: 1.6765933s. Lock duration: -68.7735933s
17/02/2024 2:53:57 AM: egg: Msg 16. Lag: 1.6731629s. Lock duration: -99.8221629s
17/02/2024 2:54:28 AM: egg: Msg 17. Lag: 1.6731869s. Lock duration: -130.8631869s
17/02/2024 2:54:59 AM: egg: Msg 18. Lag: 1.6877771s. Lock duration: -161.9017771s
17/02/2024 2:55:30 AM: egg: Msg 19. Lag: 1.6800192s. Lock duration: -192.9430192s
17/02/2024 2:56:01 AM: egg: Msg 20. Lag: 1.6842333s. Lock duration: -223.9862333s
17/02/2024 2:56:32 AM: egg: Msg 21. Lag: 1.7100187s. Lock duration: -255.0480187s
17/02/2024 2:57:03 AM: egg: Msg 22. Lag: 1.6784764s. Lock duration: -286.1474764s
17/02/2024 2:57:34 AM: egg: Msg 23. Lag: 1.6831129s. Lock duration: -317.1941129s
17/02/2024 2:58:05 AM: egg: Msg 24. Lag: 1.6806557s. Lock duration: -348.2446557s
17/02/2024 2:58:36 AM: egg: Msg 25. Lag: 1.6857493s. Lock duration: -379.2857493s
17/02/2024 2:59:07 AM: egg: Msg 26. Lag: 1.6888228s. Lock duration: -410.3358228s
17/02/2024 2:59:38 AM: egg: Msg 27. Lag: 1.6901601s. Lock duration: -441.3761601s
17/02/2024 3:00:09 AM: egg: Msg 28. Lag: 1.6780946s. Lock duration: -472.4340946s
17/02/2024 3:00:40 AM: egg: Msg 29. Lag: 1.6834788s. Lock duration: -503.4764788s
17/02/2024 3:01:11 AM: egg: Msg 30. Lag: 1.6848989s. Lock duration: -534.5108989s
17/02/2024 3:01:42 AM: egg: Msg 31. Lag: 1.6769508s. Lock duration: -565.5599508s
17/02/2024 3:02:13 AM: egg: Msg 32. Lag: 1.7033479s. Lock duration: -596.6203479s
17/02/2024 3:02:44 AM: egg: Msg 33. Lag: 1.6845338s. Lock duration: -627.6695338s
17/02/2024 3:03:16 AM: egg: Msg 34. Lag: 1.6864937s. Lock duration: -658.7074937s
17/02/2024 3:03:47 AM: egg: Msg 35. Lag: 1.6874179s. Lock duration: -689.7534179s
17/02/2024 3:04:18 AM: egg: Msg 36. Lag: 1.692409s. Lock duration: -720.808409s
17/02/2024 3:04:49 AM: egg: Msg 37. Lag: 1.6867796s. Lock duration: -751.8567796s
17/02/2024 3:05:20 AM: egg: Msg 38. Lag: 1.685359s. Lock duration: -782.911359s
17/02/2024 3:05:51 AM: egg: Msg 39. Lag: 1.6918786s. Lock duration: -813.9578786s
17/02/2024 3:06:22 AM: egg: Msg 40. Lag: 1.7100995s. Lock duration: -845.0340995s
17/02/2024 3:06:53 AM: egg: Msg 41. Lag: 1.6885905s. Lock duration: -876.0795905s
17/02/2024 3:07:24 AM: egg: Msg 42. Lag: 1.6984153s. Lock duration: -907.1304153s
17/02/2024 3:07:55 AM: egg: Msg 43. Lag: 1.7071609s. Lock duration: -938.2871609s
17/02/2024 3:08:26 AM: egg: Msg 44. Lag: 1.6953873s. Lock duration: -969.3753873s
17/02/2024 3:08:57 AM: egg: Msg 45. Lag: 1.690651s. Lock duration: -1000.441651s
17/02/2024 3:09:28 AM: egg: Msg 46. Lag: 1.6910603s. Lock duration: -1031.4970603s
17/02/2024 3:09:59 AM: egg: Msg 47. Lag: 1.6923991s. Lock duration: -1062.5333991s
17/02/2024 3:10:30 AM: egg: Msg 48. Lag: 1.68681s. Lock duration: -1093.59881s
17/02/2024 3:11:01 AM: egg: Msg 49. Lag: 1.6951195s. Lock duration: -1124.6461195s
17/02/2024 3:11:33 AM: egg: Msg 50. Lag: 1.6816297s. Lock duration: -1155.6886297s
17/02/2024 3:12:04 AM: egg: Msg 51. Lag: 1.7438724s. Lock duration: -1186.7878724s
17/02/2024 3:12:35 AM: egg: Msg 52. Lag: 1.6974936s. Lock duration: -1217.7934936s
...
17/02/2024 3:36:58 AM: egg: Msg 99. Lag: 1.7057607s. Lock duration: -2680.9357607s
//sender stopped
17/02/2024 3:40:58 AM: SessionClosingHandler egg

from azure-sdk-for-net.

After 6+ minutes, messages continue to be received on the same handler. The ProcessSessionMessageEventArgs.SessionLockedUntil time becomes negative.

I think you are saying that the SessionLockedUntil time ends up being in the past yet you are still receiving messages for the session. The service allows the session to remain locked as long as the session is being actively received from even if the lockedUntil time has past. So this is expected behavior. If you want the session to close early you can use the ReleaseSession method.

from azure-sdk-for-net.

Hi @bramley-jetcharge. Thank you for opening this issue and giving us the opportunity to assist. We believe that this has been addressed. If you feel that further discussion is needed, please add a comment with the text "/unresolve" to remove the "issue-addressed" label and continue the conversation.

from azure-sdk-for-net.

/unresolve

Hi, thanks for the info. So a session will remain locked so long as my application is running and I haven't released it, regardless of MaxAutoLockRenewalDuration value? In that case, what is the purpose of this setting? I wrote my code initially just to understand the difference between this and SessionIdleTimeout, and how I should configure them for my scenario:

I will have several thousand IoT devices, each sending frequent msgs to their own session. I will have several receiver instances, each with MaxConcurrentSessions = 1000, MaxAutoLockRenewalDuration = Timeout.Infinite (?), SessionIdleTimeout = TimeSpan.FromMinutes(60). The intention is for the processor to be locked to a session indefinitely (days or weeks), until either it stops sending msgs (>60 mins), or I explicitly ReleaseSession() it. I want to ensure msgs are always processed promptly, with no lag or starvation.

Do you see any issues with this approach?

Thanks very much

from azure-sdk-for-net.

Hi, thanks for the info. So a session will remain locked so long as my application is running and I haven't released it, regardless of MaxAutoLockRenewalDuration value? In that case, what is the purpose of this setting?

The behavior is up to the service implementation of the feature, but essentially this is what happens. The setting is useful in the case that your message processing takes more time than the actual receiving of messages. If that is your scenario, you wouldn't be actively receiving during the time that you are processing the message (i.e. after the message has already been received but before the processor attempts to receive the next message).

I will have several thousand IoT devices, each sending frequent msgs to their own session. I will have several receiver instances, each with MaxConcurrentSessions = 1000, MaxAutoLockRenewalDuration = Timeout.Infinite (?), SessionIdleTimeout = TimeSpan.FromMinutes(60). The intention is for the processor to be locked to a session indefinitely (days or weeks), until either it stops sending msgs (>60 mins), or I explicitly ReleaseSession() it. I want to ensure msgs are always processed promptly, with no lag or starvation.

A MaxConcurrentSessions value of 1000 may lead to thread starvation. I'd suggest starting with a lower value and then tuning to reach desired throughput/queue message latency. Other than that, I think this approach makes sense.

from azure-sdk-for-net.

Hi @bramley-jetcharge. Thank you for opening this issue and giving us the opportunity to assist. To help our team better understand your issue and the details of your scenario please provide a response to the question asked above or the information requested above. This will help us more accurately address your issue.

from azure-sdk-for-net.

Hi @bramley-jetcharge, we're sending this friendly reminder because we haven't heard back from you in 7 days. We need more information about this issue to help address it. Please be sure to give us your input. If we don't hear back from you within 14 days of this comment the issue will be automatically closed. Thank you!

from azure-sdk-for-net.