This is related to a previous post about the Exchange iApp. Everything is working for both internal and internal connections except from Outlook Anywhere clients attempting to connect to the external VS and auth via RPC over HTTP. I enabled all debug logs for APM and ECA since that seemed to be where the failure was occuring. I noticed the following and cannot make much sense of it. Any help would be appreciated. Below is the log file comparison between a successful auth though the internal iApp vs the failed auth through the external iApp. This is just a snippet of the full log. Everything before these lines in the log is the same for both internal and external connections. It seems to fail when the BigIP tries to make a call to itself to process the logon request, anyone ever see this before? Internal success: Aug 12 13:22:12 JHHCF5 debug eca[7237]: 0162000c:7: [Common] 10.1.12.9:46380 (0x09a8b9c8) Server challenge: 24296533D8C59FB4 Aug 12 13:22:12 JHHCF5 debug nlad[8603]: 01620000:7: <0x559058f0> clntsvc: processing 'logon' request on connection[18] from 127.0.0.1:43935 Aug 12 13:22:12 JHHCF5 debug nlad[8603]: 01620000:7: <0x559058f0> client[5]: is ready Aug 12 13:22:12 JHHCF5 debug nlad[8603]: 01620000:7: <0x5624cb90> NLAD_TRACE: nlclnt[53403010a / 01] sending logon = 0xC00000E5 Aug 12 13:22:12 JHHCF5 debug nlad[8603]: 01620000:7: <0x5624cb90> nlclnt[53403010a] logon: entering user GRicketts domain JHHC wksta JHHC04619LT Failed auth: Aug 12 12:51:10 JHHCF5 debug nlad[8603]: 01620000:7: <0x559058f0> clntsvc: processing 'logon' request on connection[38] from 127.0.0.1:44495 Aug 12 12:51:10 JHHCF5 warning nlad[8603]: 01620000:4: <0x559058f0> clntsvc: no client for id 6 to service request from connection[38] from 127.0.0.1:44495 Aug 12 12:51:10 JHHCF5 debug nlad[8603]: 01620000:7: <0x559058f0> nla_rq: response with status [0xc00000ab,NT_STATUS_INSTANCE_NOT_AVAILABLE] for type 'logon' client 6 context 0x5ab82b90 24 bytes to connection[38] from 127.0.0.1:44495: took 0 milli-seconds Aug 12 12:51:10 JHHCF5 debug eca[7237]: 0162000c:7: [Common] 12.181.141.210:45214 (0x5bf14c28) nla_agent::logon, rc = STATUS_NO_LOGON_SERVERS (3221225566)

It's hard to say what's going on here with the information provided. Do you have solid connectivity to the domain controllers? Do you have different virtuals servers for external and internal, and if so are the APM policies configured the same? Is it the same user trying to logon in both cases? You should probably open a support case with F5 on this. If you post the case here I can track it and try to help wherever I can.

hey Mike, thanks for tagging along here. I do have two different iApps configured the exact same way, the only difference being my VS IP is different. One public IP and one internal IP. I did not reuse any profiles while configuring the 2nd iApp, everything was newly created. I am authenticating with my user account in both scenarios. I had the issue before where iRules did not carry over correctly and profiles were in different partition paths but that is not the case currently. I know my DC connectivity is fine because I am using the same domain controllers for both the external and internal iApps, internal works, external does not. The logs almost indicate that the problem is internal to the BigIP since it's using the loopback IP and trying to open a service to respond to the logon request. I do have a case open for this. C1898067. Thanks for the help! I can get you full logs too if you think it will help. That is the fork in the road though between success and failure. everything prior to in the APM log file is exactly the same for that connection.

and again the interesting part about this is when I initially configured the iApp everything worked as expected. It wasn't until after a period of time where it would fail. I am at a loss right now.

Hi, Did you try to renew NTLM machine account password?

That is unusual, and this not a use case that we've specifically tested; normally we'd see APM deployed only for the external clients. You've said you created new APM configs for both; are you using the same delegation and machine accounts for both configs? After it stops working, if you run "bigstart restart websso" on the BIG-IP, does it start working again? I looked at your case but couldn't find an iHealth upload for it. If you can post one I will take a look.

Kerberos Delegation and NTLM auth Exchange 2013

38 Replies

kunjan_118660
Cumulonimbus
Aug 14, 2015
After restarting nlad has the error changed?

I think for working internal connection, nlad was communicating with DC over already established schannel. This might have established with a old machine account credentials initially.

When machine account is renewed/updated, the NTLMauth still uses old machine account info. need to restart nlad or make changes on ntlm auth to trigger the update on ntlm auth to use the new machine account credentials.

It fails when schannel is terminated and reestablished after couple of days. This could have happened for external. And when nlad restarted affected internal as well.

Now if we look at the logs, for the successful NTLM Auth

Aug 12 13:22:12 JHHCF5 debug nlad[8603]: 01620000:7: <0x559058f0>
client[5]
: is ready

Here it works with service-id mapped with 5. Refer this under ntlm-auth config,example

apm ntlm ntlm-auth /Common/xxx { dc-fqdn-list { xxxx } machine-account-name /Common/xxxx service-id 5 }

For failed NTLM-Auth, it complains about service-id 6.

Aug 12 12:51:10 JHHCF5 warning nlad[8603]: 01620000:4: <0x559058f0> clntsvc: no client for id 6 to service request from connection[38] from 127.0.0.1:44495

It seems it cannot get the machine account. Not sure how it happened. Also verify if indeed there is ntlm-auth with service-id 6. service-id increments when there is change to ntlm-auth config.

May be you could try to renew the machine password, see if this successful. Check the logs. Then restart nlad and see any err logs while it is started, before OA is accessed. May be want to try recreating the ntlm-auth config.
- Greg_130338
  Nimbostratus
  Aug 14, 2015
  Got it, this is very helpful, I did not know that the client[] referenced a service-id under the ntlm auth config. How can I show this config via command line? I will check documentation on this as well. I did attempt to renew the machine account password previously (a few days ago) and it was successful. However after I restarted nlad yesterday, I started to receive ECA debug errors as well. So I figured I'd restart ECA as well, with no change, both ntlm auth attempts fail for both internal and external iApps. After that I figured like you said to just start from scratch on the ntlm auth config. I attempted to renew the machine account password, it failed. I tried to remove the account which also failed (but likely because it is tied to an access policy already). I tried to create a new machine account which also failed. NEW ECA Debug logs on failed OA exchange connection: Aug 14 07:58:17 JHHCF5 debug eca[16121]: 01620012:7: (0x5bf48ee0) TMEVT_OPEN Aug 14 07:58:17 JHHCF5 info eca[16121]: 0162000b:6: [Common] 10.1.12.9:63069 New connection on virtual /Common/exchange_int_iapp.app/exchange_int_iapp_combined_https Aug 14 07:58:17 JHHCF5 debug eca[16121]: 01620012:7: (0x5bf48ee0) TMEVT_REQUEST Aug 14 07:58:17 JHHCF5 debug eca[16121]: 0162000c:7: [Common] 10.1.12.9:63069 (0x5bf48ee0) 6 headers received, iov_count: 1 Aug 14 07:58:17 JHHCF5 debug eca[16121]: 0162000c:7: [Common] 10.1.12.9:63069 (0x5bf48ee0) Header: :method: RPC_OUT_DATA Aug 14 07:58:17 JHHCF5 debug eca[16121]: 0162000c:7: [Common] 10.1.12.9:63069 (0x5bf48ee0) Header: :uri: /rpc/rpcproxy.dll?VMCAS01.jhhc.com:6002 Aug 14 07:58:17 JHHCF5 debug eca[16121]: 0162000c:7: [Common] 10.1.12.9:63069 (0x5bf48ee0) Header: Host: email.jhhc.com Aug 14 07:58:17 JHHCF5 debug eca[16121]: 0162000c:7: [Common] 10.1.12.9:63069 (0x5bf48ee0) Header: Authorization: NTLM TlRMTVNTUAABAAAAB4IIogAAAAAAAAAAAAAAAAAAAAAGAbEdAAAADw== Aug 14 07:58:17 JHHCF5 debug eca[16121]: 0162000c:7: [Common] 10.1.12.9:63069 (0x5bf48ee0) Header: Cookie: OutlookSession="{89DE0638-A161-4C6E-8E7E-AB53F2AAB02D} Outlook=14.0.7108.5000 OS=6.1.7601" Aug 14 07:58:17 JHHCF5 debug eca[16121]: 0162000c:7: [Common] 10.1.12.9:63069 (0x5bf48ee0) Header: :custommeta: select_ntlm:/Common/exchange_int_iapp.app/exch_ntlm_combined_https Aug 14 07:58:17 JHHCF5 debug eca[16121]: 0162000c:7: [Common] 10.1.12.9:63069 (0x5bf48ee0) Received metadata (select_ntlm:/Common/exchange_int_iapp.app/exch_ntlm_combined_https) Aug 14 07:58:17 JHHCF5 debug eca[16121]: 01620012:7: eca_module_ntlm.cpp:770 ntlm_cfg_process_op_find_set_cfg, err = ECA_ERR_NOT_FOUND Aug 14 07:58:17 JHHCF5 debug eca[16121]: 01620012:7: eca_module_ntlm.cpp:728 ntlm_cfg_handler, err = ECA_ERR_NOT_FOUND Aug 14 07:58:17 JHHCF5 err eca[16121]: 0162000e:3: Invalid argument (/Common/exchange_int_iapp.app/exch_ntlm_combined_https) Aug 14 07:58:17 JHHCF5 err eca[16121]: 0162000e:3: Invalid metadata (select_ntlm:/Common/exchange_int_iapp.app/exch_ntlm_combined_https) Aug 14 07:58:17 JHHCF5 debug eca[16121]: 01620012:7: (0x5bf48ee0) TMEVT_REQUEST_DONE Aug 14 07:58:17 JHHCF5 debug eca[16121]: 01620012:7: (0x5bf48ee0) TMEVT_ABORT_PROXY Aug 14 07:58:17 JHHCF5 debug eca[16121]: 01620012:7: (0x5bf48ee0) TMEVT_CLOSE Aug 14 07:58:17 JHHCF5 info eca[16121]: 0162000b:6: [Common] 10.1.12.9:63069 Connection is closed At this point I went ahead and changed the NTLM auth settings to basic for the iApp just so I can remove the NTLM machine account. When attempting to recreate, here are the debug APM logs upon creation attempt (I think these are the relevant logs). Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 01490000:7: Utils/Sys.cpp func: "queryIpv6Preference()" line: 121 Msg: Retrieving Sys::Dns Info Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 01490000:7: Utils/MCPInterface.cpp func: "send()" line: 436 Msg: Querying for config: Class: 4826 Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 01490000:7: Utils/MCPInterface.cpp func: "send()" line: 445 Msg: Querying for config: with constraint 4827 = /Common/dns Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 01490000:7: Utils/MCPInterface.cpp func: "send()" line: 445 Msg: Querying for config: with constraint 4829 = include Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 01490000:7: Utils/MCPInterface.cpp func: "send()" line: 445 Msg: Querying for config: with constraint 4830 = dns Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 01490000:7: Utils/MCPInterface.cpp func: "send()" line: 445 Msg: Querying for config: with constraint 4828 = Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 01490175:5: Prefer resolving hostname with IPv4 address Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: Using the following server settings: Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: domain name = 'JHHC.COM' Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: domain controller = 'JHHCDC01.JHHC.COM' Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: admin name = 'gricketts1' Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: admin password = ****** Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: PADATA encryption type = Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: none Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: Other settings specified for the test: Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: test type: AD Domain Join Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: userName: Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: concurrency: 1 Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: CCache file root: /var/run/krb5cc Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: output file: Aug 14 08:12:31 JHHCF5 notice adutil[30741]: 0149019f:5: urlDecoded: 0 Aug 14 08:12:31 JHHCF5 err adutil[30741]: 01490200:3: thread 0 started Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 01490000:7: Utils/Sys.cpp func: "getIpv6Preference()" line: 46 Msg: Prefer IPv6: false Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 0149019d:7: Using '127.0.0.1' as a Name Server Aug 14 08:12:31 JHHCF5 debug adutil[30741]: 0149019d:7: verifyKrb5Cache(): Credentials cache file '/var/run/krb5cc/ADTest/krb5cc_0_apmd' not found, func=krb5_cc_set_flag(0), ticket cache FILE:/var/run/krb5cc/ADTest/krb5cc_0_apmd Aug 14 08:12:49 JHHCF5 err adutil[30741]: 01490200:3: ERROR: Could not connect to domain domain controller of realm 'JHHC.COM' Aug 14 08:12:49 JHHCF5 debug adutil[30741]: 0149019d:7: do_connect: error = -1 Aug 14 08:12:49 JHHCF5 err adutil[30741]: 01490200:3: ERROR: domain join for 'JHHC-F5' failed: (0) Aug 14 08:12:49 JHHCF5 debug adutil[30741]: 0149019d:7: (): (0) Aug 14 08:12:49 JHHCF5 debug adutil[30741]: 0149019d:7: Aug 14 08:12:49 JHHCF5 notice adutil[30741]: 0149019f:5: thrd_id[0]: succ_cnt=0, fail_cnt=1 All I get from the logs is it failed bc it could not connect to the DC. Same error I get in the GUI. Not sure why, the domain controllers are available and actively processing AAA requests for other services. I am using the same DA account I used previously to create the last machine account. Any help is appreciated, I am almost to the point where I should just bounce the box.
kunjan
Nimbostratus
Aug 13, 2015
How about doing
bigstart restart nlad
?
- Greg_130338
  Nimbostratus
  Aug 13, 2015
  well I tried it anyway. It didn't fix the issue and actually now the internal connection fails as well with the same error.
- Greg_130338
  Nimbostratus
  Aug 13, 2015
  Do you know the impact of this? I see the definition of this service in the documentation, but would this impact communications with other AAA services, for example, for my citrix users that point to back end DC for authentication? Or this is only for access policies where an ntlm profile is assigned?
kunjan_118660
Cumulonimbus
Aug 13, 2015
How about doing
bigstart restart nlad
?
- Greg_130338
  Nimbostratus
  Aug 13, 2015
  well I tried it anyway. It didn't fix the issue and actually now the internal connection fails as well with the same error.
- Greg_130338
  Nimbostratus
  Aug 13, 2015
  Do you know the impact of this? I see the definition of this service in the documentation, but would this impact communications with other AAA services, for example, for my citrix users that point to back end DC for authentication? Or this is only for access policies where an ntlm profile is assigned?
Stanislas_Piro2
Cumulonimbus
Aug 13, 2015
Hi,

Did you try to renew NTLM machine account password?
mikeshimkus_111
Historic F5 Account
Aug 12, 2015
It's hard to say what's going on here with the information provided. Do you have solid connectivity to the domain controllers? Do you have different virtuals servers for external and internal, and if so are the APM policies configured the same? Is it the same user trying to logon in both cases? You should probably open a support case with F5 on this. If you post the case here I can track it and try to help wherever I can.
- mikeshimkus_111
  Historic F5 Account
  Aug 13, 2015
  That is unusual, and this not a use case that we've specifically tested; normally we'd see APM deployed only for the external clients. You've said you created new APM configs for both; are you using the same delegation and machine accounts for both configs? After it stops working, if you run "bigstart restart websso" on the BIG-IP, does it start working again? I looked at your case but couldn't find an iHealth upload for it. If you can post one I will take a look.
- Greg_130338
  Nimbostratus
  Aug 12, 2015
  and again the interesting part about this is when I initially configured the iApp everything worked as expected. It wasn't until after a period of time where it would fail. I am at a loss right now.
- Greg_130338
  Nimbostratus
  Aug 12, 2015
  hey Mike, thanks for tagging along here. I do have two different iApps configured the exact same way, the only difference being my VS IP is different. One public IP and one internal IP. I did not reuse any profiles while configuring the 2nd iApp, everything was newly created. I am authenticating with my user account in both scenarios. I had the issue before where iRules did not carry over correctly and profiles were in different partition paths but that is not the case currently. I know my DC connectivity is fine because I am using the same domain controllers for both the external and internal iApps, internal works, external does not. The logs almost indicate that the problem is internal to the BigIP since it's using the loopback IP and trying to open a service to respond to the logon request. I do have a case open for this. C1898067. Thanks for the help! I can get you full logs too if you think it will help. That is the fork in the road though between success and failure. everything prior to in the APM log file is exactly the same for that connection.