Forum Discussion
Greg_130338
Nimbostratus
NimbostratusKerberos Delegation and NTLM auth Exchange 2013
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...
kunjan_118660
Cumulonimbus
CumulonimbusAfter 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]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:44495It 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_130338Nimbostratus
NimbostratusGot 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.