Currently I'm dealing with a multi thread issue on a server program with .NET 6.0. The method with issue likes below:
private async Task<Cell> LoadCell()
{
if (_loadingLock.TryEnterUpgradeableReadLock(new TimeSpan(0, 0, 0, 0, 20)))
{
_globalReadlockCountEnter++;
Log.Info("_loadingLock Enter upgrade readlock, count: " + _globalReadlockCountEnter);
try
{
if (_mapLock.TryEnterReadLock(new TimeSpan(0, 0, 0, 0, 20)))
{
try
{
//Try get value
}
finally
{
_mapLock.ExitReadLock();
}
}
else
{
throw new TimeoutException("Timeout trying to get read lock in level cell manager.");
}
bool acquired = false;
try
{
if (!_loadingLock.TryEnterWriteLock(new TimeSpan(0, 0, 0, 20)))
{
throw new TimeoutException("Timeout trying to get write lock in level cell manager.");
}
else
{
acquired = true;
_globalWritelockCountEnter++;
Log.Info("_loadingLock Enter writelock, count: " + _globalWritelockCountEnter);
//deal with certain value
}
}
catch (Exception e)
{
throw new Exception("Unknown exception error.");
}
finally
{
if (acquired)
{
if (!_loadingLock.IsWriteLockHeld)
{
Log.Warn("write lock has not been held, check is everything alright?");
}
_loadingLock.ExitWriteLock();
_globalWritelockCountExit++;
Log.Info("_loadingLock exit writelock, count: " + _globalWritelockCountExit);
}
else
{
Log.Warn("acquire is false some how it failed to exit the write lock.");
}
}
}
finally
{
if (!_loadingLock.IsUpgradeableReadLockHeld)
{
Log.Warn("upgrade read lock has not been held, check is everything alright?");
}
_loadingLock.ExitUpgradeableReadLock();
_globalReadlockCountExit++;
Log.Info("_loadingLock Exit upgrade readlock, count: " + _globalReadlockCountExit);
}
}
else
{
throw new TimeoutException("Timeout trying to get upgrade read lock in level cell manager.");
}
}
The logs and error messages are like:
2023-07-19 07:43:48,601 INFO _loadingLock Exit upgrade readlock, count: 1060
2023-07-19 07:43:48,601 INFO _loadingLock Enter upgrade readlock, count: 1061
2023-07-19 07:43:48,601 INFO _loadingLock Enter writelock, count: 358
2023-07-19 07:43:48,602 INFO _loadingLock exit writelock, count: 358
2023-07-19 07:43:48,602 INFO _loadingLock Exit upgrade readlock, count: 1061
2023-07-19 07:43:48,602 INFO _loadingLock Enter upgrade readlock, count: 1062
2023-07-19 07:43:48,602 INFO _loadingLock Enter writelock, count: 359
2023-07-19 07:43:48,603 INFO _loadingLock exit writelock, count: 359
2023-07-19 07:43:48,603 INFO _loadingLock Exit upgrade readlock, count: 1062
2023-07-19 07:43:48,603 INFO _loadingLock Enter upgrade readlock, count: 1063
2023-07-19 07:43:48,603 INFO _loadingLock Exit upgrade readlock, count: 1063
2023-07-19 07:43:48,604 INFO _loadingLock Enter upgrade readlock, count: 1064
2023-07-19 07:43:48,604 INFO _loadingLock Exit upgrade readlock, count: 1064
2023-07-19 07:43:48,604 INFO _loadingLock Enter upgrade readlock, count: 1065
2023-07-19 07:43:48,604 INFO _loadingLock Exit upgrade readlock, count: 1065
...
2023-07-19 07:43:48,604 INFO _loadingLock Enter upgrade readlock, count: 1080
2023-07-19 07:43:48,604 INFO _loadingLock Exit upgrade readlock, count: 1080
2023-07-19 07:43:48,604 INFO _loadingLock Enter upgrade readlock, count: 1081
2023-07-19 07:43:48,604 INFO _loadingLock Exit upgrade readlock, count: 1081
2023-07-19 07:43:48,604 INFO _loadingLock Enter upgrade readlock, count: 1082
2023-07-19 07:43:48,604 INFO _loadingLock Enter writelock, count: 360
2023-07-19 07:43:48,623 WARN write lock has not been held, check is everything alright?
2023-07-19 07:43:48,623 WARN upgrade read lock has not been held, check is everything alright?
Unhandled exception. Unhandled exception. System.Threading.SynchronizationLockException: The upgradeable lock is being released without being held.
The issue seems happened occasionally when the method is being called, sometimes it can keep two days without any issue and sometimes it happens just after the server start for a while, and every time before it happens, all enter/exit lock could be paired. I tried spamming the logs to check what happened, and as you can see above, I finally found it's always the write lock doesn't get exit(or at least I didn't see the log when it should exit) and then when it goes the exit upgradeable read lock, exception throws.
I thought from the code the workflow should be alright that enter upgradeable readlock -> enter writelock -> exit writelock -> exit upgradeable readlock and it shouldn't cause any trouble as the example mentioned in official documentation, but in actual case, I'm not sure whether it's something I did wrong or it concerns something of base level which I'm not familiar with. As I understood, the upgradeable readlock should be something that deals with the race condition, so the lock shouldn't be released by another thread. Also I know that for IsXXXLockHeld property, as mentioned in official docs: This property is intended for use in asserts or for other debugging purposes. Do not use it to control the flow of program execution(Mention this here as I've seen that in some simular issues that some one recommand using this for flow control).
I've tried using both try or none-try enter lock method but the result is usually same, well, if uses none-try enter lock it sometimes throw exceptions at the enterUpgradeableReadlock step, give me a feeling that previous lock has not exited.
Not sure what to do know and any tip or help is appreciated.