Darwin DirectoryServices (warnnings)
Arran Cudbard-Bell
A.Cudbard-Bell at sussex.ac.uk
Fri Oct 12 16:12:00 CEST 2007
Hi,
Running radiusd 2.0pre2 (cvs head)
Just checked the system logs on one of our radius servers, and i'm
seeing some strange error messages from directory services.
Oct 12 12:02:50 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 675 open references when
the warning limit is 500.
Oct 12 12:03:00 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 675 open references when
the warning limit is 500.
Oct 12 12:18:37 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 700 open references when
the warning limit is 500.
Oct 12 12:18:40 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 700 open references when
the warning limit is 500.
Oct 12 12:35:25 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 725 open references when
the warning limit is 500.
Oct 12 12:36:25 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 725 open references when
the warning limit is 500.
Oct 12 12:49:30 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 750 open references when
the warning limit is 500.
Oct 12 12:49:35 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 750 open references when
the warning limit is 500.
Oct 12 13:05:07 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 775 open references when
the warning limit is 500.
Oct 12 13:05:49 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 775 open references when
the warning limit is 500.
Oct 12 13:20:15 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 800 open references when
the warning limit is 500.
Oct 12 13:21:00 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 800 open references when
the warning limit is 500.
Oct 12 13:35:59 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 825 open references when
the warning limit is 500.
Oct 12 13:36:42 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 825 open references when
the warning limit is 500.
Oct 12 13:45:22 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 850 open references when
the warning limit is 500.
Oct 12 13:46:34 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 850 open references when
the warning limit is 500.
Oct 12 13:59:09 wolverine DirectoryService[54]: Potential VM growth in
DirectoryService since client PID: 9179, has 875 open references when
the warning limit is 500.
PID 9179 is radiusd.
So it would seem that radiusd has an ever increasing number of
references (though I have no idea what it means in this context),
against the DirectoryServices Deamon.
With API debugging on I see
Oct 12 14:15:28 wolverine DirectoryService[54]: Client PID: 9179, has
896 open references.
Oct 12 14:15:28 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsOpenDirService(), Server Used : Result: 0, Duration: 223.47
usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsFindDirNodes(), Server Used : Result: 0, Duration: 106.71 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Client PID: 9179, has
897 open references.
Oct 12 14:15:28 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsOpenDirNode(), Search Used : Result: 0, Duration: 28.95 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Client PID: 0, has 12
open references.
Oct 12 14:15:28 wolverine DirectoryService[54]: Internal Dispatch, API:
dsOpenDirNode(), NetInfo Used : Result: 0, Duration: 86.25 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Internal Dispatch, API:
dsGetRecordList(), NetInfo Used : Result: 0, Duration: 1254.36 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Client PID: 0, has 13
open references.
Oct 12 14:15:28 wolverine DirectoryService[54]: Internal Dispatch, API:
dsOpenDirNode(), LDAPv3 Used : Result: 0, Duration: 29.37 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Internal Dispatch, API:
dsGetRecordList(), LDAPv3 Used : Result: 0, Duration: 14146.63 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsGetRecordList(), Search Used : Result: 0, Duration:
16787.38 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Client PID: 9179, has
896 open references.
Oct 12 14:15:28 wolverine DirectoryService[54]: Client PID: 0, has 12
open references.
Oct 12 14:15:28 wolverine DirectoryService[54]: Ref table dealloc
callback, API Call: dsCloseDirNode(), PlugIn Used: NetInfo, Result: 0,
Duration: 76.38 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Internal Dispatch, API:
dsCloseDirNode(), NetInfo Used : Result: 0, Duration: 2.55 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Client PID: 0, has 11
open references.
Oct 12 14:15:28 wolverine DirectoryService[54]: Ref table dealloc
callback, API Call: dsCloseDirNode(), PlugIn Used: LDAPv3, Result: 0,
Duration: 12.99 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Internal Dispatch, API:
dsCloseDirNode(), LDAPv3 Used : Result: 0, Duration: 3.03 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Ref table dealloc
callback, API Call: dsCloseDirNode(), PlugIn Used: Search, Result: 0,
Duration: 1597.26 usec
Oct 12 14:15:28 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsCloseDirNode(), Search Used : Result: 0, Duration: 2.37 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client PID: 9179, has
897 open references.
Oct 12 14:16:15 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsOpenDirService(), Server Used : Result: 0, Duration: 190.35
usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsFindDirNodes(), Server Used : Result: 0, Duration: 99.75 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client PID: 9179, has
898 open references.
Oct 12 14:16:15 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsOpenDirNode(), Search Used : Result: 0, Duration: 76.86 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client PID: 0, has 12
open references.
Oct 12 14:16:15 wolverine DirectoryService[54]: Internal Dispatch, API:
dsOpenDirNode(), NetInfo Used : Result: 0, Duration: 101.01 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Internal Dispatch, API:
dsGetRecordList(), NetInfo Used : Result: 0, Duration: 1476.36 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client PID: 0, has 13
open references.
Oct 12 14:16:15 wolverine DirectoryService[54]: Internal Dispatch, API:
dsOpenDirNode(), LDAPv3 Used : Result: 0, Duration: 28.98 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Internal Dispatch, API:
dsGetRecordList(), LDAPv3 Used : Result: 0, Duration: 13866.31 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsGetRecordList(), Search Used : Result: 0, Duration:
16742.50 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client PID: 9179, has
897 open references.
Oct 12 14:16:15 wolverine DirectoryService[54]: Client PID: 0, has 12
open references.
Oct 12 14:16:15 wolverine DirectoryService[54]: Ref table dealloc
callback, API Call: dsCloseDirNode(), PlugIn Used: NetInfo, Result: 0,
Duration: 82.14 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Internal Dispatch, API:
dsCloseDirNode(), NetInfo Used : Result: 0, Duration: 2.34 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client PID: 0, has 11
open references.
Oct 12 14:16:15 wolverine DirectoryService[54]: Ref table dealloc
callback, API Call: dsCloseDirNode(), PlugIn Used: LDAPv3, Result: 0,
Duration: 12.99 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Internal Dispatch, API:
dsCloseDirNode(), LDAPv3 Used : Result: 0, Duration: 2.49 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Ref table dealloc
callback, API Call: dsCloseDirNode(), PlugIn Used: Search, Result: 0,
Duration: 1156.36 usec
Oct 12 14:16:15 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsCloseDirNode(), Search Used : Result: 0, Duration: 3.06 usec
Oct 12 14:16:26 wolverine DirectoryService[54]: Client PID: 9179, has
898 open references.
Oct 12 14:16:26 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsOpenDirService(), Server Used : Result: 0, Duration: 233.04
usec
Oct 12 14:16:26 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsFindDirNodes(), Server Used : Result: 0, Duration: 106.62 usec
Oct 12 14:16:26 wolverine DirectoryService[54]: Client PID: 9179, has
899 open references.
Oct 12 14:16:26 wolverine DirectoryService[54]: Client: radiusd, PID:
9179, API: dsOpenDirNode(), Search Used : Result: 0, Duration: 25.83 usec
Oct 12 14:16:26 wolverine DirectoryService[54]: Client PID: 0, has 12
open references.
Oct 12 14:16:26 wolverine DirectoryService[54]: Internal Dispatch, API:
dsOpenDirNode(), NetInfo Used : Result: 0, Duration: 92.43 usec
Oct 12 14:16:26 wolverine DirectoryService[54]: Internal Dispatch, API:
dsGetRecordList(), NetInfo Used : Result: 0, Duration: 1470.36 usec
Oct 12 14:16:26 wolverine DirectoryService[54]: Client PID: 0, has 13
open references.
Oct 12 14:16:26 wolverine DirectoryService[54]: Internal Dispatch, API:
dsOpenDirNode(), LDAPv3 Used : Result: 0, Duration: 31.86 usec
Anyone have any idea whats going on ....
Could this explain the possible memory leak in radiusd, that only seems
to appear on Darwin ?
--
Arran Cudbard-Bell (A.Cudbard-Bell at sussex.ac.uk)
Authentication, Authorisation and Accounting Officer
Infrastructure Services | ENG1 E1-1-08
University Of Sussex, Brighton
EXT:01273 873900 | INT: 3900
More information about the Freeradius-Users
mailing list