Darwin DirectoryServices (warnnings)
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@sussex.ac.uk) Authentication, Authorisation and Accounting Officer Infrastructure Services | ENG1 E1-1-08 University Of Sussex, Brighton EXT:01273 873900 | INT: 3900
Arran Cudbard-Bell wrote:
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.
Hmm... the only OpenDirectory code in the server is in rlm_mschap. If you set "use_open_directory = no" in the rlm_mschap configuration, this issue *should* go away. Unless, of course, you're actually using OpenDirectory. In which case, the bug would need fixing.
Could this explain the possible memory leak in radiusd, that only seems to appear on Darwin ?
Yup. Alan DeKok.
Alan DeKok wrote:
Arran Cudbard-Bell wrote:
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.
Hmm... the only OpenDirectory code in the server is in rlm_mschap. If you set "use_open_directory = no" in the rlm_mschap configuration, this issue *should* go away.
Thanks, DirectoryServices API debugging shows radiusd is no longer making calls against OpenDirectory, will test patch from Steve Simon on monday.
Unless, of course, you're actually using OpenDirectory. In which case, the bug would need fixing.
Nah.
Could this explain the possible memory leak in radiusd, that only seems to appear on Darwin ?
Yup.
Early private memory usage stats still aren't looking good, i'll give it some more time to settle though. Arran
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (2)
-
Alan DeKok -
Arran Cudbard-Bell