Application Delivery Management
Application Modernization & Connectivity
CyberRes by OpenText
IT Operations Management
Recently at a client, I was helping get AppleShare IP connectivity, for use with the AppleShare File Protocol (AFP) working.
Usually on NetWare 6.5 this is pretty much ready to go out of the box, as it is enabled by default during the install.
However, as we worked through the possibilities, it just plain was not working. Thankfully we were able to track down the issues (three of them in a row in fact!) and get it all going. This article is meant to be the story of how we did it, so that anyone else seeing any of our three issues can see how we fixed them, but also to show the approach we took. For others who see similar but not identical issues, this article can help show how to approach diagnosing the problem.
Lets start with the environment, as it turns out to have mattered. We were actually trying to get Kanaka from Condrey Consulting working on a Mac 10.5 (Leopard) Mac Book Pro. We wanted to connect Macs to a two node NetWare 6.5 SP8 cluster (Technically that is OES2 I guess, NetWare kernel).
I wrote a troubleshooting article for Kanaka a few years ago that reminded me of some of the easy things that needed to be fixed: Kanaka Troubleshooting
All the easy stuff was done, and yet we could not connect. The easy stuff was making sure that AFPSTRT.NCF was in the autoexec.ncf and loaded. Making sure the sys:\etc\cxts.cfg included the context of the user we were working with. Making sure the user had a Universal Password set (actually our first test user did NOT have a Universal Password). To diagnose the Universal Password issue we used Jim Willeke's excellent tool, Dump Universal Password which is available at: Password Information Tool
Once the basics are all taken care of, it is time to try and find the error messages, and resolve them one by one. First things first, you need to know how Macintosh clients authenticate to NetWare via the AFPTCP.NLM. They use NMAS (Novell Modular Authentication Services) which is a module that eDirectory trusts and is allowed to use alternate password methods, like smart cards, biometrics, or AppleShare File Protocol style passwords to log in to eDirectory. After all, the eDirectory password is usually stored as an RSA public and private key pair. This is a Novell specific implementation and only Novell tools usually directly support it. The Prosoft Client for Macs would be an example of a third party tool that supports the NDS password, and provides NCP (Novell Core Protocol) support on a Macintosh computer.
In order to provide access to other password styles, Novell first tried Simple Password, which they quickly moved away from into Universal Password. In the Universal Password case, the password is stored AES encrypted in a hidden attribute in eDirectory. Only NMAS is allowed access to it, (Unless you explicitly allow Admin to recover it). The SDI tree keys are used to encrypt and decrypt those secrets. The Universal password is recoverable and therefore for something like an AFP login, which uses something called two way random number hashing, logins can be processed.
To watch these events happen as users login, you need to watch in NMAS trace. NMAS trace used to be a separate module before eDirectory was so cross platform. To solve the cross platform issue, Novell added NMAS tracing into the Dstrace facility that is built into eDirectory. Other services like Novell Identity Manager, PKI, LDAP, etc all show their trace information in the same place.
Look at this article The Many Faces of DSTRACE for more information about how to get at Dstrace.
In my case, we used the web interface, via iMonitor to get at Dstrace. Basically, we knew the server we would be authenticating too, and we selected it as not many others would be, so the trace would be less cluttered. Open a web browser to http://ServerIP:8008 and we should get redirected to port 8009 over HTTPS and asked to login.
Select Manage eDirectory, the iMonitor. On the toolbar click on the jagged lightning bolt icon which is DStrace. On the configuration page, we selected Clear All to remove the various default trace settings and enabled only NMAS (at the very bottom of the page, there is a separate session for extra trace tags).
On our first login attempt, we saw the following trace. I will be posting the entire traces, because my hope is that someone who does a Google search on keywords out of their trace example will find this article that way. Also, it will show you each step of the way, what we were looking at and looking for.
11:38:27 94F970A0 NMAS: 14: Destroy NMAS Session for reuse
11:38:27 94F970A0 NMAS: 14: Create NMAS Session
11:38:27 94F970A0 NMAS: 14: CheckIfLocalUser: client supplied user DN jsmith.o=acme.c=us
11:38:27 94F970A0 NMAS: 14: CheckIfLocalUser: checking actual user DN CN=JSmith.O=ACME.C=US
11:38:27 94F970A0 NMAS: 14: Create thread request
11:38:27 94F970A0 NMAS: 14: Using thread 0x8f9d6008
11:38:27 94F970A0 NMAS: 14: Server thread started
11:38:27 94F970A0 NMAS: 14: NMAS_CanDo StartClientSession 0
11:38:27 9ABD1360 NMAS: 14: Pool thread 0x8f9d6008 awake with new work
11:38:27 94F970A0 NMAS: 14: ClientPut: message size=8 queue Size 0
11:38:27 94F970A0 NMAS: 14: ClientPut: message size=7 queue Size 8
11:38:27 94F970A0 NMAS: 14: NMAS_CanDo sendMessage 0
11:38:27 94F970A0 NMAS: 14: ClientGet: message size=8 queue Size 0
11:38:27 9ABD1360 NMAS: 14: ServerGet: message size=8 queue size 15
11:38:27 9ABD1360 NMAS: 14: ServerGet: message size=7 queue size 7
11:38:27 9ABD1360 NMAS: 14: CanDo
11:38:27 9ABD1360 NMAS: 14: updateLoginStatistics configured failed login delay 3
11:38:27 9ABD1360 NMAS: 14: Sequence Selected == "Macintosh Native File Access"
11:38:27 9ABD1360 NMAS: 14: Login Sequence Macintosh Native File Access not valid.
11:38:27 9ABD1360 NMAS: 14: Login Sequence NDS is valid.
11:38:27 9ABD1360 NMAS: 14: Login Sequence Challenge Response is valid.
11:38:27 9ABD1360 NMAS: 14: Login Sequence Simple Password is valid.
11:38:27 9ABD1360 NMAS: 14: Login Sequence Enhanced Password is valid.
11:38:27 9ABD1360 NMAS: 14: ERROR: -1660 CanDo
11:38:27 9ABD1360 NMAS: 14: ERROR: -1660 NMAS Manager
11:38:27 9ABD1360 NMAS: 14: Failed login
11:38:30 9ABD1360 NMAS: 14: ServerPut: message size=8 queue size 0
11:38:30 9ABD1360 NMAS: 14: ServerPut: message size=4 queue size 8
11:38:30 9ABD1360 NMAS: 14: ServerGet: message size=8 queue size 0
11:38:30 94F970A0 NMAS: 14: ClientGet: message size=4 queue Size 4
11:38:30 94F970A0 NMAS: 14: NMAS_CanDo getMessage 0
11:38:30 94F970A0 NMAS: 14: Client Session Destroy Request
11:38:30 94F970A0 NMAS: 14: Local Session Cleared (Not Destroyed)
11:38:30 9ABD1360 NMAS: 14: ServerGet: session cleared
11:38:30 9ABD1360 NMAS: 14: Server thread exited
11:38:30 9ABD1360 NMAS: 14: Pool thread 0x8f9d6008 work complete
This was our first error, and probably the single biggest problem we had to clear up along the way. The rest of the errors we ran into were basically minor configuration things. Whereas this one was the root cause.
First note that clearly our sys:\etc\cxts.cfg file was correct as these two lines show that we found our user correctly:
11:38:27 94F970A0 NMAS: 14: CheckIfLocalUser: client supplied user DN jsmith.o=acme.c=us
11:38:27 94F970A0 NMAS: 14: CheckIfLocalUser: checking actual user DN CN=JSmith.O=ACME.C=US
Looking at the trace, the key portion that should catch your eye is this segment:
11:38:27 9ABD1360 NMAS: 14: Sequence Selected == "Macintosh Native File Access"
11:38:27 9ABD1360 NMAS: 14: Login Sequence Macintosh Native File Access not valid.
11:38:27 9ABD1360 NMAS: 14: Login Sequence NDS is valid.
11:38:27 9ABD1360 NMAS: 14: Login Sequence Challenge Response is valid.
11:38:27 9ABD1360 NMAS: 14: Login Sequence Simple Password is valid.
11:38:27 9ABD1360 NMAS: 14: Login Sequence Enhanced Password is valid.
11:38:27 9ABD1360 NMAS: 14: ERROR: -1660 CanDo
11:38:27 9ABD1360 NMAS: 14: ERROR: -1660 NMAS Manager
We got a 1660 NMAS error, and that seems to be caused because our Macintosh Native File Access method is not valid. What is that all about? Well thankfully, right off the bat we have an error code we can search Novell's support knowledge base about and see what we find.
These two TID's came in really handy.
Unable to access CIFS/NFAP share on NetWare server
Troubleshooting NMAS -1660 errors with NMAS Login Methods
We worked through the steps, and in the end, it looks like our problem was that inexplicably, this eDirectory tree never really got the Macintosh login method properly installed. Now I would have said that is nuts, as just three weeks ago a new NetWare 6.5 server had been installed in the tree, and I am pretty sure that sets up the login methods by default if they are not currently set.
Regardless that was our first issue. We had to use Console One with the NMAS snapins, and in the Security container (at the [Root] of the tree) and in the Login Methods object, define a Macintosh Native File Access sequence (use the New Sequence tab and the name must be a perfect spelling match) and from the list of Authorized login sequences add just the Macintosh Native File Access method. Seems kind of silly, but you actually need one defined, and our tree did not actually have one.
11:46:03 9ABD1360 NMAS: NMAS Login Policy Refresh Started
11:46:03 9ABD1360 NMAS: Sequence name Challenge Response
11:46:03 9ABD1360 NMAS: Type: AND Grade: 0x800000
11:46:03 9ABD1360 NMAS: Login Methods: 0x1F
11:46:03 9ABD1360 NMAS: Sequence name Simple Password
11:46:03 9ABD1360 NMAS: Type: AND Grade: 0x4000000
11:46:03 9ABD1360 NMAS: Login Methods: 0x9
11:46:03 9ABD1360 NMAS: Sequence name Enhanced Password
11:46:03 9ABD1360 NMAS: Type: AND Grade: 0x800000
11:46:03 9ABD1360 NMAS: Login Methods: 0x14
11:46:03 9ABD1360 NMAS: Loading Proxy LCM Method ID: 0x1E Grade: 0x800000 MIB: 1 Flags: 0x1
11:46:03 9ABD1360 NMAS: ERROR: -16049 Read Macintosh Native File Access Proxy LCM Code
11:46:03 9ABD1360 NMAS: Login Method name: Macintosh Native File Access
11:46:03 9ABD1360 NMAS: Method ID: 0x1E Grade: 0x800000 Flags: 0x1
11:46:03 9ABD1360 NMAS: LSM Module Name: LSMAFP3.NLM
11:46:03 9ABD1360 NMAS: LSM Entry Point Name: LSMAFP3
11:46:03 9ABD1360 NMAS: Update count: 1 LMO GUID: 80a97d08f14db11
11:46:03 9ABD1360 NMAS: Loading Proxy LCM Method ID: 0x22 Grade: 0x800000 MIB: 1 Flags: 0x1
11:46:03 9ABD1360 NMAS: Loading Proxy LCM Method ID: 0x22 Grade: 0x800000 MIB: 1 Flags: 0x1
11:46:03 9ABD1360 NMAS: Login Method name: Windows Native File Access
11:46:03 9ABD1360 NMAS: Method ID: 0x22 Grade: 0x800000 Flags: 0x1
11:46:03 9ABD1360 NMAS: LSM Module Name: LSMCIFS2.NLM
11:46:03 9ABD1360 NMAS: LSM Entry Point Name: LSMCIFS2
11:46:03 9ABD1360 NMAS: Proxy LCM Module Name: LCMCIFS2.NLM
11:46:03 9ABD1360 NMAS: Proxy LCM Entry Point Name: LCMCIFS2
11:46:03 9ABD1360 NMAS: Update count: 1 LMO GUID: 81a97d08f14db11
11:46:03 9ABD1360 NMAS: Sequence name NDS
11:46:03 9ABD1360 NMAS: Type: AND Grade: 0x800000
11:46:03 9ABD1360 NMAS: Login Methods: 0x7, 0x1E, 0x22
11:46:03 9ABD1360 NMAS: SASL mechanism name: NMAS_LOGIN
11:46:03 9ABD1360 NMAS: NMAS Login Policy Refresh Finished
Once we were done creating the Login sequence we needed, we had executed NMAS REFRESHPOLICY at the server console, which should unload the LSM modules, and reload them as you can see in the trace above.
Would you believe that the LSM (Login Sequence Methods) actually store the executable code for each platform, as attributes on the objects in eDirectory? This is why not all LSMs are supported on all platforms, especially for older methods that were never updated to be cross platform.
12:02:00 948DD520 NMAS: 24: Create NMAS Session
12:02:00 948DD520 NMAS: 24: CheckIfLocalUser: client supplied user DN admin.OU=Servers.O=NYC.C=US
12:02:00 948DD520 NMAS: ERROR: -601 resolveFilteredReplica: Resolving .admin.OU=Servers.O=NYC.C=US.DK.
12:02:00 948DD520 NMAS: ERROR: -601 dal_createUserContext: resolveFilteredReplica for admin.OU=Servers.O=NYC.C=US
12:02:00 948DD520 NMAS: ERROR: -16049 createDALSession:createUserContext
12:02:00 948DD520 NMAS: 24: ERROR: -16049 CheckIfLocalUser: DALCreateLoginSession
12:02:00 948DD520 NMAS: 24: CheckIfLocalUser failed -16049
12:02:00 948DD520 NMAS: 24: Client Session Destroy Request
12:02:00 948DD520 NMAS: 24: Destroy NMAS Session
12:02:00 948DD520 NMAS: 24: Aborted Session Destroyed (with MAF)
12:02:00 948DD520 NMAS: 25: Destroy NMAS Session for reuse
12:02:00 948DD520 NMAS: 25: Create NMAS Session
12:02:00 948DD520 NMAS: 25: CheckIfLocalUser: client supplied user DN admin.OU=Servers.O=NYC.C=US
12:02:00 948DD520 NMAS: ERROR: -601 resolveFilteredReplica: Resolving .admin.OU=Servers.O=NYC.C=US.DK.
12:02:00 948DD520 NMAS: ERROR: -601 dal_createUserContext: resolveFilteredReplica for admin.OU=Servers.O=NYC.C=US
12:02:00 948DD520 NMAS: ERROR: -16049 createDALSession:createUserContext
12:02:00 948DD520 NMAS: 25: ERROR: -16049 CheckIfLocalUser: DALCreateLoginSession
12:02:00 948DD520 NMAS: 25: CheckIfLocalUser failed -16049
12:02:00 948DD520 NMAS: 25: Client Session Destroy Request
12:02:00 948DD520 NMAS: 25: Destroy NMAS Session
12:02:00 948DD520 NMAS: 25: Aborted Session Destroyed (with MAF)
Then I tried to see if I could get a CIFS login from the Mac, not just an AFP connection. In this case, the Admin user I tried to login with did not exist in the locations in the sys:etc\cifsctxs.cfg file. Thus the 601 error, could not find the file, then the 16049 more generic NMAS error.
I went back to AFP logins as I thought I was on to something. and after creating the Macintosh Native File Access login sequence I saw the following in NMAS trace:
12:12:37 8F999440 NMAS: 38: Create NMAS Session
12:12:37 8F999440 NMAS: 38: CheckIfLocalUser: client supplied user DN jsmith.o=acme.c=us
12:12:37 8F999440 NMAS: 38: CheckIfLocalUser: checking actual user DN CN=JSmith.O=ACME.C=US
12:12:37 8F999440 NMAS: 38: Create thread request
12:12:37 8F999440 NMAS: 38: Using thread 0x8f9d6008
12:12:37 8F999440 NMAS: 38: Server thread started
12:12:37 8F999440 NMAS: 38: NMAS_CanDo StartClientSession 0
12:12:37 8F999440 NMAS: 38: ClientPut: message size=8 queue Size 0
12:12:37 9ABD1360 NMAS: 38: Pool thread 0x8f9d6008 awake with new work
12:12:37 8F999440 NMAS: 38: ClientPut: message size=7 queue Size 8
12:12:37 8F999440 NMAS: 38: NMAS_CanDo sendMessage 0
12:12:37 8F999440 NMAS: 38: ClientGet: message size=8 queue Size 0
12:12:37 9ABD1360 NMAS: 38: ServerGet: message size=8 queue size 15
12:12:37 9ABD1360 NMAS: 38: ServerGet: message size=7 queue size 7
12:12:37 9ABD1360 NMAS: 38: CanDo
12:12:37 9ABD1360 NMAS: 38: updateLoginStatistics configured failed login delay 3
12:12:37 9ABD1360 NMAS: 38: Sequence Selected == "Macintosh Native File Access"
12:12:37 9ABD1360 NMAS: 38: Login Sequence Macintosh Native File Access not authorized for JSmith.ACME.US
12:12:37 9ABD1360 NMAS: 38: ERROR: -1680 CanDo
12:12:37 9ABD1360 NMAS: 38: ERROR: -1680 NMAS Manager
12:12:37 9ABD1360 NMAS: 38: Failed login
12:12:40 9ABD1360 NMAS: 38: ServerPut: message size=8 queue size 0
12:12:40 9ABD1360 NMAS: 38: ServerPut: message size=4 queue size 8
12:12:40 9ABD1360 NMAS: 38: ServerGet: message size=8 queue size 0
12:12:40 8F999440 NMAS: 38: ClientGet: message size=4 queue Size 4
12:12:40 8F999440 NMAS: 38: NMAS_CanDo getMessage 0
12:12:40 8F999440 NMAS: 38: Client Session Destroy Request
12:12:40 8F999440 NMAS: 38: Local Session Cleared (Not Destroyed)
12:12:40 9ABD1360 NMAS: 38: ServerGet: session cleared
12:12:40 9ABD1360 NMAS: 38: Server thread exited
12:12:40 9ABD1360 NMAS: 38: Pool thread 0x8f9d6008 work complete
Well thats a new error. Before we saw the line "Login Sequence Macintosh Native File Access not valid" now we see "Login Sequence Macintosh Native File Access not authorized for JSmith.ACME.US" with a 1680 error. Well that we can look up, and the issue is we need to authorize the users to use the newly created login sequence.
Here is what the Novell KB has to say about 1680 errors:
-1680 Error returned to client using an NMAS Login Method
The default is to allow all users all the login sequences, but somewhere in this tree, it has been restricted. We can override it at the Organization or Organizational Unit level, by adding an attribute sasAuthorizedLoginSequences to be a multi valued attribute, first with NDS then second with Macintosh Native File Access (matching the name of the sequence we created earlier). To allow CIFS access, we would have to add Windows Native File Access to that list as well.
Initially though we used the NMAS snapin in Console One, edited User, Security Tab, limited to only these methods (All available methods) and we saw the following:
12:15:00 94F970A0 NMAS: 39: CheckIfLocalUser: client supplied user DN jsmith.o=acme.c=us
12:15:00 94F970A0 NMAS: 39: CheckIfLocalUser: checking actual user DN CN=JSmith.O=ACME.C=US
12:15:00 94F970A0 NMAS: 39: Create thread request
12:15:00 94F970A0 NMAS: 39: Using thread 0x8f9d6008
12:15:00 94F970A0 NMAS: 39: Server thread started
12:15:00 94F970A0 NMAS: 39: NMAS_CanDo StartClientSession 0
12:15:00 9ABD1360 NMAS: 39: Pool thread 0x8f9d6008 awake with new work
12:15:00 94F970A0 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:00 94F970A0 NMAS: 39: ClientPut: message size=7 queue Size 8
12:15:00 94F970A0 NMAS: 39: NMAS_CanDo sendMessage 0
12:15:00 94F970A0 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 15
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=7 queue size 7
12:15:00 9ABD1360 NMAS: 39: CanDo
12:15:00 9ABD1360 NMAS: 39: updateLoginStatistics configured failed login delay 3
12:15:00 9ABD1360 NMAS: 39: Sequence Selected == "Macintosh Native File Access"
12:15:00 9ABD1360 NMAS: 39: Login Method 0x0000001E
12:15:00 9ABD1360 NMAS: 39: MAF_Begin LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=5 queue size 8
12:15:00 94F970A0 NMAS: 39: ClientGet: message size=5 queue Size 5
12:15:00 94F970A0 NMAS: 39: NMAS_CanDo getMessage 0
12:15:00 94F970A0 NMAS: 39: NMAS_CanDo disassembleDoPacket 0
12:15:00 94F970A0 NMAS: 39: MAF_Begin LCM 0x00000000
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetAuthRequest
12:15:00 9ABD1360 NMAS: 39: MAF_Read LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 0
12:15:00 94F970A0 NMAS: 39: AFPTCP: utilProxyLogin posting 3 request
12:15:00 94F970A0 NMAS: 39: MAF_Write LCM 0x00000000
12:15:00 94F970A0 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:00 94F970A0 NMAS: 39: ClientPut: message size=14 queue Size 8
12:15:00 94F970A0 NMAS: 39: MAF_Read LCM 0x00000000
12:15:00 94F970A0 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=14 queue size 14
12:15:00 9ABD1360 NMAS: 39: MAF_Write LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=12 queue size 8
12:15:00 9ABD1360 NMAS: 39: MAF_Read LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 0
12:15:00 94F970A0 NMAS: 39: ClientGet: message size=12 queue Size 12
12:15:00 94F970A0 NMAS: 39: MAF_Write LCM 0x00000000
12:15:00 94F970A0 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:00 94F970A0 NMAS: 39: ClientPut: message size=1614 queue Size 8
12:15:00 94F970A0 NMAS: 39: AFPTCP: utilProxyLogin Getting response
12:15:00 94F970A0 NMAS: 39: MAF_Read LCM 0x00000000
12:15:00 94F970A0 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=1614 queue size 1614
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: . . . GetAuthRequest completed
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetRandomNum
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: WriteReply
12:15:00 9ABD1360 NMAS: 39: MAF_Write LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=14 queue size 8
12:15:00 9ABD1360 NMAS: 39: MAF_Read LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 0
12:15:00 94F970A0 NMAS: 39: ClientGet: message size=14 queue Size 14
12:15:00 94F970A0 NMAS: 39: MAF_Write LCM 0x00000000
12:15:00 94F970A0 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:00 94F970A0 NMAS: 39: ClientPut: message size=12 queue Size 8
12:15:00 94F970A0 NMAS: 39: MAF_Read LCM 0x00000000
12:15:00 94F970A0 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=12 queue size 12
12:15:00 9ABD1360 NMAS: 39: MAF_Write LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=1614 queue size 8
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: .... Write Reply completed
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: info->request = 3
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetAuthRequest
12:15:00 9ABD1360 NMAS: 39: MAF_Read LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 0
12:15:00 94F970A0 NMAS: 39: ClientGet: message size=1614 queue Size 1614
12:15:00 94F970A0 NMAS: 39: AFPTCP: authenticated = 1 (1)
12:15:00 8F999440 NMAS: 39: AFPTCP: Starting ProxyLoginCont
12:15:00 8F999440 NMAS: 39: MAF_Write LCM 0x00000000
12:15:00 8F999440 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:00 8F999440 NMAS: 39: ClientPut: message size=14 queue Size 8
12:15:00 8F999440 NMAS: 39: MAF_Read LCM 0x00000000
12:15:00 8F999440 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=14 queue size 14
12:15:00 9ABD1360 NMAS: 39: MAF_Write LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=12 queue size 8
12:15:00 9ABD1360 NMAS: 39: MAF_Read LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 0
12:15:00 8F999440 NMAS: 39: ClientGet: message size=12 queue Size 12
12:15:00 8F999440 NMAS: 39: MAF_Write LCM 0x00000000
12:15:00 8F999440 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:00 8F999440 NMAS: 39: ClientPut: message size=1614 queue Size 8
12:15:00 8F999440 NMAS: 39: MAF_Read LCM 0x00000000
12:15:00 8F999440 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=1614 queue size 1614
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: . . . GetAuthRequest completed
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: CommonRandomNumAuthent
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetUniversalPassword
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: Calling MAF_GetPassword
12:15:00 9ABD1360 NMAS: 39: ERROR: -1697 MAF_GetPassword LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: MAF_GetPassword returned -1697 <fffff95f>, grace logins remaining = 0
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetUniversalPassword: MAF_GetPassword failed with error -1697 <0xfffff95f>
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: Universal Passwords are turned OFF. See Universal Password Deployment Guide.
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetSimplePassword
12:15:00 9ABD1360 NMAS: 39: ERROR: -16049 MAF_GetAttribute LSM 0x0000001E AID: 24
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetSimplePassword: MAF_GetAttribute failed with error -16049 <0xffffc14f>
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: Could not get Universal Password or Simple Password.
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: Second ProcessAuthRequest returned -16049 <ffffc14f> authenticated = 0
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: WriteReply
12:15:00 9ABD1360 NMAS: 39: MAF_Write LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=14 queue size 8
12:15:00 9ABD1360 NMAS: 39: MAF_Read LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 0
12:15:00 8F999440 NMAS: 39: ClientGet: message size=14 queue Size 14
12:15:00 8F999440 NMAS: 39: MAF_Write LCM 0x00000000
12:15:00 8F999440 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:00 8F999440 NMAS: 39: ClientPut: message size=12 queue Size 8
12:15:00 8F999440 NMAS: 39: MAF_Read LCM 0x00000000
12:15:00 8F999440 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=12 queue size 12
12:15:00 9ABD1360 NMAS: 39: MAF_Write LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:00 9ABD1360 NMAS: 39: ServerPut: message size=1614 queue size 8
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: .... Write Reply completed
12:15:00 9ABD1360 NMAS: 39: ERROR: -1 MAF_End LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 0
12:15:00 8F999440 NMAS: 39: ClientGet: message size=1614 queue Size 1614
12:15:00 8F999440 NMAS: 39: AFPTCP: authenticated from LSMAFP is 0 <0>
12:15:00 8F999440 NMAS: 39: MAF_End LCM 0x00000000
12:15:00 8F999440 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:00 8F999440 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:00 9ABD1360 NMAS: 39: WhatNext
12:15:00 9ABD1360 NMAS: 39: Failed login
12:15:03 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:03 9ABD1360 NMAS: 39: ServerPut: message size=4 queue size 8
12:15:03 8F999440 NMAS: 39: ClientGet: message size=4 queue Size 4
12:15:03 8F999440 NMAS: 39: ClientPut: message size=8 queue Size 0
12:15:03 8F999440 NMAS: 39: ClientGet: message size=8 queue Size 0
12:15:03 9ABD1360 NMAS: 39: ServerGet: message size=8 queue size 8
12:15:03 9ABD1360 NMAS: 39: ServerPut: message size=8 queue size 0
12:15:03 9ABD1360 NMAS: 39: Server thread exited
12:15:03 9ABD1360 NMAS: 39: Pool thread 0x8f9d6008 work complete
12:15:03 8F999440 NMAS: 39: Client Session Destroy Request
12:15:03 8F999440 NMAS: 39: Local Session Cleared (Not Destroyed)
Basically we got significantly further in the process, having cleared up the 1660 and then the 1680 error, but this time we ran into a funny one, this particular user did not have a Universal Password set! You can see it very clearly in the log.
12:15:00 9ABD1360 NMAS: 39: ERROR: -1697 MAF_GetPassword LSM 0x0000001E
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: MAF_GetPassword returned -1697 <fffff95f>, grace logins remaining = 0
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetUniversalPassword: MAF_GetPassword failed with error -1697 <0xfffff95f>
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: Universal Passwords are turned OFF. See Universal Password Deployment Guide.
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetSimplePassword
12:15:00 9ABD1360 NMAS: 39: ERROR: -16049 MAF_GetAttribute LSM 0x0000001E AID: 24
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: GetSimplePassword: MAF_GetAttribute failed with error -16049 <0xffffc14f>
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: Could not get Universal Password or Simple Password.
12:15:00 9ABD1360 NMAS: 39: ..LSMAFP3: Second ProcessAuthRequest returned -16049 <ffffc14f> authenticated = 0
Discussed it and realized this was an admin account excluded from Identity Manager, and that is why it did not have a UP, so we moved on to another account to test with.
Success! Here is a complete successful log in NMAS trace of what an AFP login SHOULD look like!
12:18:45 9ABD1360 NMAS: 41: ServerPut: message size=8 queue size 0
12:18:45 9ABD1360 NMAS: 41: ServerPut: message size=4 queue size 8
12:18:45 9ABD1360 NMAS: 41: ServerGet: message size=8 queue size 0
12:18:45 8F999440 NMAS: 41: ClientGet: message size=4 queue Size 4
12:18:45 8F999440 NMAS: 41: NMAS_CanDo getMessage 0
12:18:45 8F999440 NMAS: 41: Client Session Destroy Request
12:18:45 8F999440 NMAS: 41: Local Session Cleared (Not Destroyed)
12:18:45 9ABD1360 NMAS: 41: ServerGet: session cleared
12:18:45 9ABD1360 NMAS: 41: Server thread exited
12:18:45 9ABD1360 NMAS: 41: Pool thread 0x8f9d6008 work complete
12:18:56 94F970A0 NMAS: 42: Destroy NMAS Session for reuse
12:18:56 94F970A0 NMAS: 42: Create NMAS Session
12:18:56 94F970A0 NMAS: 42: CheckIfLocalUser: client supplied user DN bjones.ou=techs.o=acme.c=us
12:18:56 94F970A0 NMAS: 42: CheckIfLocalUser: checking actual user DN CN=BJones.OU=Techs.O=ACME.C=US
12:18:56 94F970A0 NMAS: 42: Create thread request
12:18:56 94F970A0 NMAS: 42: Using thread 0x8f9d6008
12:18:56 94F970A0 NMAS: 42: Server thread started
12:18:56 94F970A0 NMAS: 42: NMAS_CanDo StartClientSession 0
12:18:56 9ABD1360 NMAS: 42: Pool thread 0x8f9d6008 awake with new work
12:18:56 94F970A0 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 94F970A0 NMAS: 42: ClientPut: message size=7 queue Size 8
12:18:56 94F970A0 NMAS: 42: NMAS_CanDo sendMessage 0
12:18:56 94F970A0 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 15
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=7 queue size 7
12:18:56 9ABD1360 NMAS: 42: CanDo
12:18:56 9ABD1360 NMAS: 42: updateLoginStatistics configured failed login delay 3
12:18:56 9ABD1360 NMAS: 42: Sequence Selected == "Macintosh Native File Access"
12:18:56 9ABD1360 NMAS: 42: Login Method 0x0000001E
12:18:56 9ABD1360 NMAS: 42: MAF_Begin LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=5 queue size 8
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: GetAuthRequest
12:18:56 9ABD1360 NMAS: 42: MAF_Read LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 0
12:18:56 94F970A0 NMAS: 42: ClientGet: message size=5 queue Size 5
12:18:56 94F970A0 NMAS: 42: NMAS_CanDo getMessage 0
12:18:56 94F970A0 NMAS: 42: NMAS_CanDo disassembleDoPacket 0
12:18:56 94F970A0 NMAS: 42: MAF_Begin LCM 0x00000000
12:18:56 94F970A0 NMAS: 42: AFPTCP: utilProxyLogin posting 3 request
12:18:56 94F970A0 NMAS: 42: MAF_Write LCM 0x00000000
12:18:56 94F970A0 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 94F970A0 NMAS: 42: ClientPut: message size=14 queue Size 8
12:18:56 94F970A0 NMAS: 42: MAF_Read LCM 0x00000000
12:18:56 94F970A0 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=14 queue size 14
12:18:56 9ABD1360 NMAS: 42: MAF_Write LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=12 queue size 8
12:18:56 9ABD1360 NMAS: 42: MAF_Read LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 0
12:18:56 94F970A0 NMAS: 42: ClientGet: message size=12 queue Size 12
12:18:56 94F970A0 NMAS: 42: MAF_Write LCM 0x00000000
12:18:56 94F970A0 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 94F970A0 NMAS: 42: ClientPut: message size=1614 queue Size 8
12:18:56 94F970A0 NMAS: 42: AFPTCP: utilProxyLogin Getting response
12:18:56 94F970A0 NMAS: 42: MAF_Read LCM 0x00000000
12:18:56 94F970A0 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=1614 queue size 1614
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: . . . GetAuthRequest completed
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: GetRandomNum
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: WriteReply
12:18:56 9ABD1360 NMAS: 42: MAF_Write LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=14 queue size 8
12:18:56 9ABD1360 NMAS: 42: MAF_Read LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 0
12:18:56 94F970A0 NMAS: 42: ClientGet: message size=14 queue Size 14
12:18:56 94F970A0 NMAS: 42: MAF_Write LCM 0x00000000
12:18:56 94F970A0 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 94F970A0 NMAS: 42: ClientPut: message size=12 queue Size 8
12:18:56 94F970A0 NMAS: 42: MAF_Read LCM 0x00000000
12:18:56 94F970A0 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=12 queue size 12
12:18:56 9ABD1360 NMAS: 42: MAF_Write LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=1614 queue size 8
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: .... Write Reply completed
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: info->request = 3
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: GetAuthRequest
12:18:56 9ABD1360 NMAS: 42: MAF_Read LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 0
12:18:56 94F970A0 NMAS: 42: ClientGet: message size=1614 queue Size 1614
12:18:56 94F970A0 NMAS: 42: AFPTCP: authenticated = 1 (1)
12:18:56 8F999440 NMAS: 42: AFPTCP: Starting ProxyLoginCont
12:18:56 8F999440 NMAS: 42: MAF_Write LCM 0x00000000
12:18:56 8F999440 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 8F999440 NMAS: 42: ClientPut: message size=14 queue Size 8
12:18:56 8F999440 NMAS: 42: MAF_Read LCM 0x00000000
12:18:56 8F999440 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=14 queue size 14
12:18:56 9ABD1360 NMAS: 42: MAF_Write LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=12 queue size 8
12:18:56 9ABD1360 NMAS: 42: MAF_Read LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 0
12:18:56 8F999440 NMAS: 42: ClientGet: message size=12 queue Size 12
12:18:56 8F999440 NMAS: 42: MAF_Write LCM 0x00000000
12:18:56 8F999440 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 8F999440 NMAS: 42: ClientPut: message size=1614 queue Size 8
12:18:56 8F999440 NMAS: 42: MAF_Read LCM 0x00000000
12:18:56 8F999440 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=1614 queue size 1614
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: . . . GetAuthRequest completed
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: CommonRandomNumAuthent
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: GetUniversalPassword
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: Calling MAF_GetPassword
12:18:56 9ABD1360 NMAS: 42: MAF_GetPassword LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: MAF_GetPassword returned 0 <0>, grace logins remaining = 0
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: Got the password
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: WriteReply
12:18:56 9ABD1360 NMAS: 42: MAF_Write LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=14 queue size 8
12:18:56 9ABD1360 NMAS: 42: MAF_Read LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 0
12:18:56 8F999440 NMAS: 42: ClientGet: message size=14 queue Size 14
12:18:56 8F999440 NMAS: 42: MAF_Write LCM 0x00000000
12:18:56 8F999440 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 8F999440 NMAS: 42: ClientPut: message size=12 queue Size 8
12:18:56 8F999440 NMAS: 42: MAF_Read LCM 0x00000000
12:18:56 8F999440 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=12 queue size 12
12:18:56 9ABD1360 NMAS: 42: MAF_Write LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=1614 queue size 8
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: .... Write Reply completed
12:18:56 9ABD1360 NMAS: 42: MAF_End LSM 0x0000001E successful
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 0
12:18:56 8F999440 NMAS: 42: ClientGet: message size=1614 queue Size 1614
12:18:56 8F999440 NMAS: 42: AFPTCP: authenticated from LSMAFP is 1 <1>
12:18:56 8F999440 NMAS: 42: MAF_End LCM 0x00000000
12:18:56 8F999440 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 8F999440 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: WhatNext
12:18:56 9ABD1360 NMAS: 42: Successful login
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=4 queue size 8
12:18:56 8F999440 NMAS: 42: ClientGet: message size=4 queue Size 4
12:18:56 8F999440 NMAS: 42: ClientPut: message size=8 queue Size 0
12:18:56 8F999440 NMAS: 42: ClientGet: message size=8 queue Size 0
12:18:56 9ABD1360 NMAS: 42: ServerGet: message size=8 queue size 8
12:18:56 9ABD1360 NMAS: 42: ServerPut: message size=8 queue size 0
12:18:56 9ABD1360 NMAS: 42: Server thread exited
12:18:56 9ABD1360 NMAS: 42: Pool thread 0x8f9d6008 work complete
12:18:56 8F999440 NMAS: 42: NMAS_SetIdentity was successful
12:18:56 8F999440 NMAS: 42: Client Session Destroy Request
12:18:56 8F999440 NMAS: 42: Local Session Cleared (Not Destroyed)
You can see the success in getting the password in these lines:
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: . . . GetAuthRequest completed
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: CommonRandomNumAuthent
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: GetUniversalPassword
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: Calling MAF_GetPassword
12:18:56 9ABD1360 NMAS: 42: MAF_GetPassword LSM 0x0000001E
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: MAF_GetPassword returned 0 <0>, grace logins remaining = 0
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: Got the password
12:18:56 9ABD1360 NMAS: 42: ..LSMAFP3: WriteReply
Once we did that having authorized just the user it worked. We then began to test with the parent container, and that worked, then we went to the Organization at the root of the tree to see if the attribute was inherited, since setting this on thousands of users was doable via Novell Identity Manager, but would seem to miss using one of the key features of eDirectory, inheritance.
Well it turns out it is inherited. This particular tree is amusing as the objects under Root are actually C=, country objects, and they do not get the schema extension automatically. We debated modifying schema to allow it, but since we only had 4 sub containers (all Organization objects) to set it on, we decided it was safer to just set it four times where schema already allows it than to fiddle around with it. Why take the risk, even if it seem minute, to save 3 attributes?
Finally we thought we had it working. Then since this was a two node cluster, we had been testing on a node with no resources loaded, under the theory if anything abended or crashed, we would not be affecting users at work. Now that all seemed to be good, it was time to test against the real cluster node and get Kanaka working for us.
When we tried the other node, nothing showed up in NMAS trace at all. This was a real head scratcher, as on the other node we at least got an error when it was not working, but something was in the NMAS trace. This time there was nothing!
Searched the Novell KB for anything related to AFP logins, and finally found a note that said that Leopard does not support the CLEARTEXT command line switch to AFPTCP.NLM.
Unable to log in using Clear Text via Leopard
I quickly looked at the second nodes sys:\system\afpstrt.ncf file and lo and behold, there it was,
load afptcp CLEARTEXT
I edited the file, did an AFPSTOP then an AFPSTRT. However since this was running on a cluster node, I had to do an AFPBIND ADD VIRT-SERVER 10.1.1.1 command at the prompt to make AFP listen on the cluster resources IP Address. (I could have migrated the cluster node away and back, but that would have interfered with users currently working and was not an option during the day).
Once we did that, we were able to connect via OS X's Connect to Server (Apple-K) command. We could mount the volumes and all seemed well.
Now as it happens, we also edited the sys:\etc\afpvol.cfg to alias the volumes on the cluster resource, because of an issue with how AFP makes clustered volumes appear.
Even though the volumes should be shown as coming from the VIRT-SERVER server name, they do not. Rather they show up as Server1.SYS, Server1.DATA and when the cluster fails over, or the resource is running on Server2, they get mounted as Server2.SYS and Server2.DATA so shortcuts on the Mac desktop do not work.
To fix this, on each server in the cluster, you remove the server name reference in the name, and it works. You do that by adding lines in the sys:\etc\afpvol.cfg file that look like the following:
Server1.SYS "sys"
Server1.DATA "data"
And then on the second node you do the same, but as follows:
Server2.SYS "sys"
Server2.DATA "data"
This way when a Mac user uses Apple-K and connects to the server, the names of the volumes are much prettier, sys and data instead of Server1.SYS or Server2.DATA. Of course you can call them anything you like to make it easier for end users to know what is going on.
Then we had to move on to troubleshoot Kanaka. But that is a story for another day, as this article is already long enough! I hope if you run into a similar problem, this helps you work through it.