NDS Client Error w/ RADIUS

[southwestern]

I'm running Radius 4.14 (from BM3.8) on a NW 6.5 box w/ SP6. I'm using
Radius for authentication from a couple banks or USR Total Control
Dialup modems (PPP).

On certain user accounts and intermittently, I get an "NDS Client
Error (-150)". Authentication fails.

Here's the Debug Log:

[2007-08-30 01:43:19 PM] -------- START : (Access-Request (1)) [(ip)
10.213.0.33:1645]: time:775429158---
[2007-08-30 01:43:19 PM] CACHE:
CacheDomainListExist(Radius_Dialup.scc), using cache
[2007-08-30 01:43:19 PM] AuthRequestHandler(), Calling
NewRequestHandler.
[2007-08-30 01:43:19 PM] CacheFindContext - GetParentDN(userDN)
(student.scc)
[2007-08-30 01:43:19 PM] CacheFindContext - tmpContext
(STUDENT.SCC), contextName([ROOT])
[2007-08-30 01:43:19 PM] Handling local authentication request.
[2007-08-30 01:43:19 PM] CACHE:
CacheReadSecretForNASAddress(Radius_Dialup.scc), using cache
[2007-08-30 01:43:19 PM]
(->)NDSVerifyAttr:NWDSRead(dkoch5782.STUDENT.SCC,RADIUS:Dial Access
Group) succeeded, time:10
[2007-08-30 01:43:19 PM] User "dkoch5782.STUDENT.SCC", does not have
"RADIUS:Dial Access Group" defined, trying parent "STUDENT.SCC"
[2007-08-30 01:43:19 PM] (->)NWDSCompare:(STUDENT.SCC) succeeded,
time:5
[2007-08-30 01:43:19 PM] (->)NWDSRead(dkoch5782.STUDENT.SCC,RADIUS
Enable Attr) failed, no such attribute (-603), time:4
[2007-08-30 01:43:19 PM] (->)User "dkoch5782.STUDENT.SCC", Looking in
(STUDENT.SCC) for (RADIUS:Enable Dial Access)
[2007-08-30 01:43:19 PM] (->)NWDSRead(STUDENT.SCC,RADIUS Enable Attr)
succeeded, time:4
[2007-08-30 01:43:19 PM] User Name: .dkoch5782.student.scc, User DN:
dkoch5782.STUDENT.SCC, Domain: , Service Tag:
[2007-08-30 01:43:19 PM] Encountered insufficient memory error,
releasing messages in ResponseQ <81>.
[2007-08-30 01:43:19 PM] -------- END : (Access-Request (1)) [(ip)
10.213.0.33:1645]: time:775429203---

Here's the log from a Radius RefreshCache:

[2007-08-30 01:42:23 PM] (->)Cacher:
NWDSReadObjectInfo(Radius_Dialup.scc), succeeded, time:2
[2007-08-30 01:42:34 PM] <Cache thread stopped>
[2007-08-30 01:42:34 PM] <Rx thread stopped>
[2007-08-30 01:42:34 PM] <Rx thread stopped>
[2007-08-30 01:42:34 PM] UnloadHandler: Unloading workers
[2007-08-30 01:42:34 PM] .[2007-08-30 01:42:34 PM] GetNextMessage()
failed, generic failure (-1)
[2007-08-30 01:42:34 PM] GetNextMessage() failed, generic failure
(-1)
[2007-08-30 01:42:34 PM] GetNextMessage() failed, generic failure
(-1)
[2007-08-30 01:42:34 PM] GetNextMessage() failed, generic failure
(-1)
[2007-08-30 01:42:34 PM] GetNextMessage() failed, generic failure
(-1)
[2007-08-30 01:42:34 PM] <Worker (4) Stopped, errL generic failure
(-1), (workers remaining = 4)>
[2007-08-30 01:42:34 PM] <Worker (1) Stopped, errL generic failure
(-1), (workers remaining = 3)>
[2007-08-30 01:42:34 PM] <Worker (0) Stopped, errL generic failure
(-1), (workers remaining = 2)>
[2007-08-30 01:42:34 PM] <Worker (2) Stopped, errL generic failure
(-1), (workers remaining = 1)>
[2007-08-30 01:42:34 PM] <Worker (3) Stopped, errL generic failure
(-1), (workers remaining = 0)>
[2007-08-30 01:42:35 PM] UnloadHandler: Unload Cache Thread
[2007-08-30 01:42:35 PM] FreeProxyQ(), Free authentication proxy
queue...
[2007-08-30 01:42:35 PM] FreeProxyQ(), Free accounting proxy
queue...
[2007-08-30 01:42:36 PM] Deleting file
"sys:etc\radius\log\20070823.log", failed
[2007-08-30 01:42:36 PM] Parameter count = 3
[2007-08-30 01:42:36 PM] argv[0] = SYS:SYSTEM\RADIUS.NLM
[2007-08-30 01:42:36 PM] argv[1] = name=.Radius_Dialup.scc
[2007-08-30 01:42:36 PM] Tree Name = "<null>"
[2007-08-30 01:42:36 PM] Login Name = "<null>"
[2007-08-30 01:42:36 PM] Name = ".Radius_Dialup.scc"
[2007-08-30 01:42:36 PM] Workers = 0
[2007-08-30 01:42:36 PM] Port = 0
[2007-08-30 01:42:36 PM] Error encountered = 0
[2007-08-30 01:42:36 PM] Checking if parameters are to be retrieved
from Registry
[2007-08-30 01:42:36 PM] Got Tree Name from registry, "<null>"
[2007-08-30 01:42:36 PM] Got Login Name from registry, "<null>"
[2007-08-30 01:42:36 PM] Got Number Threads from registry, 5
[2007-08-30 01:42:36 PM] Got Service Port from registry, 1645
[2007-08-30 01:42:36 PM] Got Accounting Port from registry, 1646
[2007-08-30 01:42:36 PM] Got Accounting Path from registry,
"sys:\etc\radius\acct"
[2007-08-30 01:42:36 PM] Got Accounting File Format from registry,
"comma"
[2007-08-30 01:42:36 PM] Got RollOver from registry, "daily"
[2007-08-30 01:42:36 PM] Services supported, [2007-08-30 01:42:36 PM]
"authentication" [2007-08-30 01:42:36 PM] "accounting" [2007-08-30
01:42:36 PM]
[2007-08-30 01:42:36 PM] Got Accounting Attribute File from registry,
sys:\etc\radius\radacct.atr
[2007-08-30 01:42:36 PM] Got Authentication Path from registry,
sys:etc\radius
[2007-08-30 01:42:41 PM] Debug logging enabled to file
sys:etc\radius\debug\raddbg.log
[2007-08-30 01:42:44 PM] Cacher: Console initiated rebuild of cache
[2007-08-30 01:42:44 PM] (->)Cacher:
NWDSReadObjectInfo(Radius_Dialup.scc), succeeded, time:2
[2007-08-30 01:42:44 PM] Cacher: Rebuilding cache, mod time different,

[2007-08-30 01:42:44 PM]
(->)NDSReadData:NWDSRead(Radius_Dialup.scc,RADIUS:DAS Version)
succeeded, time:4
[2007-08-30 01:42:44 PM]
(->)NDSReadData:NWDSRead(Radius_Dialup.scc,RADIUS:Password Policy)
failed, no such attribute (-603), time:4
[2007-08-30 01:42:44 PM]
(->)NDSReadData:NWDSRead(Radius_Dialup.scc,RADIUS:Common Name
Resolution) succeeded, time:3
[2007-08-30 01:42:44 PM]
(->)NDSReadData:NWDSRead(Radius_Dialup.scc,RADIUS:Concurrent Limit)
failed, no such attribute (-603), time:3
[2007-08-30 01:42:44 PM]
(->)NDSReadData:NWDSRead(Radius_Dialup.scc,RADIUS:Interim Accting
Timeout) failed, no such attribute (-603), time:4
[2007-08-30 01:42:44 PM]
(->)NDSReadData:NWDSRead(Radius_Dialup.scc,RADIUS:Aged Interval)
failed, no such attribute (-603), time:4
[2007-08-30 01:42:44 PM]
(->)NDSReadData:NWDSRead(Radius_Dialup.scc,RADIUS:Maximum History
Record) failed, no such attribute (-603), time:4
[2007-08-30 01:42:44 PM] CACHE: Use Netware Password for
"Radius_Dialup.scc": Enabled
[2007-08-30 01:42:44 PM] CACHE: CN Login for "Radius_Dialup.scc":
Enabled
[2007-08-30 01:42:44 PM] CACHE: Concurrent Limit for
"Radius_Dialup.scc": 0x80000000
[2007-08-30 01:42:44 PM] CACHE: Interim Timeout for
"Radius_Dialup.scc": 10 minutes
[2007-08-30 01:42:44 PM] CACHE: Interval For Aging for
"Radius_Dialup.scc": 7 days
[2007-08-30 01:42:44 PM] CACHE: Max History Record for
"Radius_Dialup.scc": 30
[2007-08-30 01:42:44 PM]
Context Lookup List set to:
[2007-08-30 01:42:44 PM] 1) AD.SCC
[2007-08-30 01:42:44 PM] 2) Adjunct.SCC
[2007-08-30 01:42:44 PM] 3) AS.SCC
[2007-08-30 01:42:44 PM] 4) BS.SCC
[2007-08-30 01:42:44 PM] 5) Cashiers.SCC
[2007-08-30 01:42:44 PM] 6) Cherokee.SCC
[2007-08-30 01:42:44 PM] 7) DCare.SCC
[2007-08-30 01:42:44 PM] 8) Dialup.SCC
[2007-08-30 01:42:44 PM] 9) Franklin.SCC
[2007-08-30 01:42:44 PM] 10) FRL.SCC
[2007-08-30 01:42:44 PM] 11) Grounds.SCC
[2007-08-30 01:42:44 PM] 12) IT.SCC
[2007-08-30 01:42:44 PM] 13) Macon.SCC
[2007-08-30 01:42:44 PM] 14) Maintenance.SCC
[2007-08-30 01:42:44 PM] 15) PSTC.SCC
[2007-08-30 01:42:44 PM] 16) Retiree.SCC
[2007-08-30 01:42:44 PM] 17) Security.SCC
[2007-08-30 01:42:44 PM] 18) SS.SCC
[2007-08-30 01:42:44 PM] 19) SSS.SCC
[2007-08-30 01:42:44 PM] 20) Student.SCC
[2007-08-30 01:42:44 PM] 21) Swain.SCC
[2007-08-30 01:42:44 PM] 22) Trustee.SCC
[2007-08-30 01:42:44 PM] 23) Jackson.GOV.SCC
[2007-08-30 01:42:44 PM] 24) Swain.GOV.SCC
[2007-08-30 01:42:44 PM] 25) Foundation.SCC
[2007-08-30 01:42:44 PM] Number of contexts = 25
[2007-08-30 01:42:44 PM] tag extracted: 10.210.8.213, size: 13,
tagLength: 26
[2007-08-30 01:42:44 PM] tag extracted: 10.209.8.213, size: 13,
tagLength: 26
[2007-08-30 01:42:44 PM] tag extracted: 10.213.0.31, size: 12,
tagLength: 24
[2007-08-30 01:42:45 PM] tag extracted: 10.213.0.32, size: 12,
tagLength: 24
[2007-08-30 01:42:46 PM] tag extracted: 10.213.0.33, size: 12,
tagLength: 24
[2007-08-30 01:42:46 PM] Cache: Successfully set up client table
[2007-08-30 01:42:46 PM] Cache: Successfully set up context list
[2007-08-30 01:42:48 PM] Cache: Successfully set up domain list
[2007-08-30 01:42:48 PM] Cache: Successfully set up search domain list
[2007-08-30 01:42:48 PM] Cache: Successfully build context list
[2007-08-30 01:42:48 PM] AdjustProxyPointers(), Adjust proxy auth
queues pointers...
[2007-08-30 01:42:48 PM] AdjustProxyPointers(), Adjust proxy acct
queues pointers...
[2007-08-30 01:42:48 PM] CACHE: Cache reloaded at [2007-08-30
01:42:48 PM], current reload count is 2
[2007-08-30 01:42:48 PM] Cacher: RefreshCache(), succeeded
[2007-08-30 01:42:48 PM] CACHE: Cache loaded at [2007-08-30 01:42:38
PM] has been discarded , current reload count is 2
[2007-08-30 01:43:19 PM] 1) [(ip) 10.213.0.33:1645], Received 135 Bytes
(Access-Request (1))
[2007-08-30 01:43:19 PM] [(total=1) (p=0) (d=0) (r=0) (acc=0)
(rej=0)]
[2007-08-30 01:43:19 PM] <2> Done GetNextMessage [(ip)
10.213.0.33:1645]: time:412354

--
southwestern

[Craig Johnson]

In article <southwest...@no-mx.nds_engineer.com>, Southwestern
wrote:

> On certain user accounts and intermittently, I get an "NDS Client
> Error (-150)". Authentication fails.
>

At other times, the same user account works OK?

Do all servers in the tree have the latest NMAS version on? (Or at
least the same version). Is it possible you have some tree-walking
going on to a server without a replica, or with an older version of
NMAS?

Craig Johnson
Novell Support Connection SysOp
*** For a current patch list, tips, handy files and books on
BorderManager, go to http://www.craigjconsulting.com ***

[southwestern]

Craig Johnson Wrote:
>
> At other times, the same user account works OK? Yes, sometimes the same account will work fine. I have some users who I
can see attempting authentication a half dozen times with the above
error, then suddenly it will auth successfully.

>
> Do all servers in the tree have the latest NMAS version on? (Or at
> least the same version). Is it possible you have some tree-walking
> going on to a server without a replica, or with an older version of

> NMAS?Hmm, that's an interesting question. We have about a dozen servers in
this replica (all r/w copies), a couple are Netware 5.0 servers that
haven't gotten upgraded yet due to hardware limitations(I only get
about two or three servers a year). The server running Radius is
holding the master copy of the replica.

Oddly, the one running Radius (NW6.5sp6) is showing NMAS 2.2
installed. The other 6.5 servers seem to all be running 3.1.2. Was
3.1.2 the version installed by NW6.5 SP6?

--
southwestern

[Craig Johnson]

In article <southwest...@no-mx.nds_engineer.com>, Southwestern
wrote:

> Oddly, the one running Radius (NW6.5sp6) is showing NMAS 2.2
> installed. The other 6.5 servers seem to all be running 3.1.2. Was
> 3.1.2 the version installed by NW6.5 SP6?
>

Maybe, but I can't recall. Security Services path 2.04 should put NMAS
3.1.3 on though, so if you are at NW65SP6, you should probably go ahead
and put on the ss204 patch on all the servers.

It does sound like some times the NMAS authentication requests are
going to a server that is not able to respond correctly, either due to
incorrect NMAS version, or some sort of eDir sync issue. I think I
would at least try reapplying sp6 on the one server that has such an
older NMAS.

[southwestern]

I'll try patching NW65 and NMAS to get everything up to current rev.

Thanks, I wasn't thinking down those lines.

I'll post back to this thread with the result either way.

--
southwestern

[Craig Johnson]

In article <southwest...@no-mx.nds_engineer.com>, Southwestern
wrote:

> I'll try patching NW65 and NMAS to get everything up to current rev.
>
> Thanks, I wasn't thinking down those lines.
>
> I'll post back to this thread with the result either way.
>

OK. I'll be interested to know if this is indeed the issue. You might
be able to confirm a tree-walk problem using NMASMON.