Those messages are part of an error check in our mutex handling routines.
Actually they pretty much mean what they say.
releaseMutex() call with an UN-LOCKED mutex
means that the corresponding accessMutex() call never occured.
releaseMutex() call with an UN-INITIALIZED mutex
means that the access/release occured before the createMutex().
The file/line comments:
[hash.c:559] last unlock [pid 22176, pbuf.c:2598]
Tell you where the access/release was called from (e.g. hash.c @ 559) and
where the last recorded release was.
None of these stop ntop from processing, but they're indications of
unprotected accesses to shared data areas, which could lead to lost counts.
There are others, look in leaks.c for the entire set.
The problem is that a POSIX mutex doesn't allow for additional data, such as
we're using to track the access / release information. So that data is,
itself protected by a single global mutex. You can't hold that global mutex
across an access call, or you'll deadlock ntop (either through normal mutex
processing or something called 'priority inversion').
So we use this pattern instead:
access(stateChangeMutex)
set state data
release(stateChangeMutex)
access(mutex) or release(mutex)
access(stateChangeMutex)
set state data
release(stateChangeMutex)
The problem is that these updates aren't atomic, so it's possible to have
the state data updated by another thread:
---------thread A--------- ---------thread B---------
access(stateChangeMutex)
set state data
access(stateChangeMutex)
*****blocked****
release(stateChangeMutex)
(resumes)
set state data
release(stateChangeMutex)
access(mutex)
****blocked****
release(mutex)
(resumes)
access(stateChangeMutex)
set state data
release(stateChangeMutex)
access(stateChangeMutex)
set state data
release(stateChangeMutex)
Unfortunately, this is equally likely:
---------thread A--------- ---------thread B---------
access(stateChangeMutex)
set state data
access(stateChangeMutex)
*****blocked****
release(stateChangeMutex)
(resumes)
set state data
release(stateChangeMutex)
access(mutex)
****blocked****
release(mutex)
(resumes)
access(stateChangeMutex)
set state data
release(stateChangeMutex)
access(stateChangeMutex)
set state data
release(stateChangeMutex)
So at the end, you have an inaccurate picture in the state table.
The release function was coded this way:
access(stateChangeMutex)
release(mutex)
set state data
release(stateChangeMutex)
which was causing deadlocks. The problem is that the release() call invokes
traceEvent() which locks a mutex to store into the log's ringbuffer. So...
it's likely that the change I did to moving the lock of the stateChangeMutex
after the release is what's causing an increase in messages. And probably
won't fix things.
Let me work on the alternate, that is using the native calls, not ntop's
enhanced ones to control the logView mutex referenced in traceEvent(). That
will keep stateChangeMutex out of the traceEvent() path, and so the
associated deadlocks...
-----Burton
PS: There's a good set of articles on POSIX threads at
http://www-106.ibm.com/developerworks/library/l-posix1/,
http://www-106.ibm.com/developerworks/library/l-posix2/ and
http://www-106.ibm.com/developerworks/library/l-posix3/.
-----Original Message-----
From: [EMAIL PROTECTED] [mailto:[EMAIL PROTECTED] Behalf
Of Kouprie, Robbert
Sent: Tuesday, August 12, 2003 8:55 AM
To: '[EMAIL PROTECTED]'
Subject: [Ntop-dev] releaseMutex() call with an UN-LOCKED mutex
Hi,
In between these two CVS versions...
drwxr-xr-x 4 root root 4096 Aug 8 14:58 ntop-cvs-20030808
drwxr-xr-x 4 root root 4096 Aug 12 10:07 ntop-cvs-20030812
... a change is made that causes my logs to be full of these:
Aug 12 15:31:36 xf ntop[22177]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [hash.c:559] last unlock [pid 22176, pbuf.c:2598]
Aug 12 15:31:47 xf ntop[22176]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [pbuf.c:2598] last unlock [pid 22177, hash.c:559]
Aug 12 15:31:47 xf ntop[22177]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [hash.c:559] last unlock [pid 22176, pbuf.c:2598]
Aug 12 15:31:56 xf ntop[22181]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [http.c:2476] last unlock [pid 22177, hash.c:588]
Aug 12 15:37:43 xf ntop[22179]: **ERROR** ERROR: releaseMutex() call with
an UN-INITIALIZED mutex [rrdPlugin.c:778]
Aug 12 15:40:34 xf ntop[23498]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [pbuf.c:591] last unlock [pid 23498, pbuf.c:591]
Aug 12 15:40:57 xf ntop[23498]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [pbuf.c:591] last unlock [pid 23494, pbuf.c:591]
Aug 12 15:44:25 xf ntop[23494]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [pbuf.c:2598] last unlock [pid 23495, hash.c:559]
Aug 12 15:46:26 xf ntop[23495]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [ntop.c:626] last unlock [pid 23494, pbuf.c:591]
Aug 12 15:47:57 xf ntop[23498]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [pbuf.c:591] last unlock [pid 23494, pbuf.c:591]
Aug 12 15:48:58 xf ntop[23498]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [pbuf.c:591] last unlock [pid 23494, pbuf.c:591]
Aug 12 15:49:27 xf ntop[23494]: **WARNING** WARNING: releaseMutex() call
with an UN-LOCKED mutex [pbuf.c:2598] last unlock [pid 23495, hash.c:559]
What does it mean? Is there something wrong that I should debug, or is it
just a harmless message that should be silenced?
-- Robbert
_______________________________________________
Ntop-dev mailing list
[EMAIL PROTECTED]
http://listgateway.unipi.it/mailman/listinfo/ntop-dev
_______________________________________________
Ntop-dev mailing list
[EMAIL PROTECTED]
http://listgateway.unipi.it/mailman/listinfo/ntop-dev
