Lots of InvalidPluginConfigurationException - A...| JBoss.org Content Archive (Read Only)

15. Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

tsegismont Feb 13, 2015 11:54 AM (in response to pathduck)

Well the org.apache.http.wire category is supposed to print a textual representation of HTTP exchanges so it's not far for your understanding

Turning a "higher" log4j category (org.apache.http) on should turn the wire category on. Not sure why it didn't work. Please explicitly turn the org.apache.http.wire category on.

Have a nice week-end!

16. Re: Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

pathduck Feb 17, 2015 4:32 AM (in response to tsegismont)

Morning Thomas,

seems org.apache.http.wire is by default overridden with ERROR so that's why we didn't see any debug even if org.apache.http is DEBUG.

Here are my observations:

- The server we set to use 'management-http' (non-SSL) has a number of times Unavailable over the weekend, some of them very long (hours)

- The server we set to use file-based auth (rhqadmin) has no reported unavailability over the same time.

So this could lead to a theory that the problem is with LDAP-authentication. I have contacted the AD-guys to see if they are aware of any problems. We have AD load-balanced behind BigIP so it might be a problem with one of the domain controllers.

I have also caught a InvalidPluginConfigurationException with wire debug.

What I see for working auth is:

2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9644 requested authentication
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.client.TargetAuthenticationStrategy)- Authentication schemes in the order of preference: [negotiate, Kerberos, NTLM, Digest, Basic]
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for negotiate authentication scheme not available
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for Kerberos authentication scheme not available
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for NTLM authentication scheme not available
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for Digest authentication scheme not available
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.client.DefaultHttpClient)- Selected authentication options: [BASIC]
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.client.protocol.RequestAddCookies)- CookieSpec selected: best-match
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.client.protocol.RequestAuthCache)- Auth cache not set in the context
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.client.protocol.RequestTargetAuthentication)- Target auth state: CHALLENGED
2015-02-16 10:22:28,013 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.client.protocol.RequestTargetAuthentication)- Generating response to an authentication challenge using basic scheme
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.client.protocol.RequestProxyAuthentication)- Proxy auth state: UNCHALLENGED
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.client.DefaultHttpClient)- Attempt 2 to execute request
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (apache.http.impl.conn.DefaultClientConnection)- Sending request: POST /management HTTP/1.1
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (org.apache.http.wire)- >> "POST /management HTTP/1.1[\r][\n]"
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (org.apache.http.wire)- >> "Accept: application/json[\r][\n]"
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (org.apache.http.wire)- >> "Content-Length: 181[\r][\n]"
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (org.apache.http.wire)- >> "Content-Type: application/json; charset=UTF-8[\r][\n]"
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (org.apache.http.wire)- >> "Host: 0.0.0.0:9644[\r][\n]"
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (org.apache.http.wire)- >> "Connection: Keep-Alive[\r][\n]"
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (org.apache.http.wire)- >> "User-Agent: Apache-HttpClient/4.2.5 (java 1.5)[\r][\n]"
2015-02-16 10:22:28,014 DEBUG [ResourceContainer.invoker.availCheck.daemon-20] (org.apache.http.wire)- >> "Authorization: Basic [\r][\n]"

However, for the thread where the auth fails I see this:

2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.DefaultClientConnection)- Receiving response: HTTP/1.1 401 Unauthorized
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- Connection can be kept alive for 5000 MILLISECONDS
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- Authentication required
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9644 requested authentication
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- Authorization challenge processed
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- Authentication failed
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.DefaultClientConnection)- Connection 0.0.0.0:45809<->10.49.67.52:9644 shut down
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.DefaultClientConnection)- Connection 0.0.0.0:45809<->10.49.67.52:9644 closed
2015-02-16 10:31:17,052 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.PoolingClientConnectionManager)- Connection released: [id: 93306][route: {s}->https://0.0.0.0:9644][total kept alive: 0; route allocated: 0 of 10; total allocated: 0 of 10]
2015-02-16 10:31:17,052 WARN  [ConfigurationManager.threadpool-1] (rhq.core.pc.configuration.ConfigurationCheckExecutor)- An error occurred while checking for an updated Resource configuration for Resource[id=12139, uuid=2442eeed-0f1d-4048-b4de-06fd5d334e37, type={JBossAS7}SocketBindingGroup, key=socket-binding-group=standard-sockets, name=standard-sockets, parent=Stilling-solr (9644)].
org.rhq.core.pluginapi.inventory.InvalidPluginConfigurationException: Credentials for plugin to connect to AS7 management interface are invalid - update Connection Settings with valid credentials.
    at org.rhq.modules.plugins.jbossas7.ASConnection.executeRaw(ASConnection.java:304)

So it does not even enter "TargetAuthenticationStrategy" negotiation at all?

Also, just an instant before the second request fails I see this:

2015-02-16 10:31:16,951 DEBUG [ASConnection Cleaner] (apache.http.impl.conn.PoolingClientConnectionManager)- Closing expired connections

2015-02-16 10:31:16,951 DEBUG [ASConnection Cleaner] (apache.http.impl.conn.PoolingClientConnectionManager)- Closing connections idle longer than 5000 MILLISECONDS

Could this be related, the connection cleaner closing the connection right before the second attempt?

I have no idea why the file-based auth seems to work though, will keep watching to see if I am able to catch any exception on this one server.

Stian

17. Re: Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

tsegismont Feb 17, 2015 5:16 AM (in response to pathduck)

Le 16/02/2015 10:55, Stian Lund a écrit :

Morning Thomas,

seems org.apache.http.wire is by default overridden with ERROR so that's
why we didn't see any debug even if org.apache.http is DEBUG.

OK

Here are my observations:

- The server we set to use 'management-http' (non-SSL) has a number of
times Unavailable over the weekend, some of them very long (hours)

OK, tends to prove the new connection over https feature is not the culprit

- The server we set to use file-based auth (rhqadmin) has no reported
unavailability over the same time.

We have a suspect

So this could lead to a theory that the problem is with
LDAP-authentication. I have contacted the AD-guys to see if they are
aware of any problems. We have AD load-balanced behind BigIP so it might
be a problem with one of the domain controllers.

I'm not sure how you can do that, but it might be interesting to get

some logs from the AS7 server side.

I have also caught a InvalidPluginConfigurationException with wire debug.

What I see for working auth is:

2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9644 requested authentication
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.client.TargetAuthenticationStrategy)- Authentication schemes in the order of preference: https://developer.jboss.org/negotiate, Kerberos, NTLM, Digest, Basic
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for negotiate authentication scheme not available
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for Kerberos authentication scheme not available
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for NTLM authentication scheme not available
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for Digest authentication scheme not available
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.client.DefaultHttpClient)- Selected authentication options: https://developer.jboss.org/BASIC
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.client.protocol.RequestAddCookies)- CookieSpec selected: best-match
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.client.protocol.RequestAuthCache)- Auth cache not set in the context
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.client.protocol.RequestTargetAuthentication)- Target auth state: CHALLENGED
2015-02-16 10:22:28,013 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.client.protocol.RequestTargetAuthentication)- Generating response to an authentication challenge using basic scheme
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.client.protocol.RequestProxyAuthentication)- Proxy auth state: UNCHALLENGED
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.client.DefaultHttpClient)- Attempt 2 to execute request
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (apache.http.impl.conn.DefaultClientConnection)- Sending request: POST /management HTTP/1.1
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (org.apache.http.wire)- >> "POST /management HTTP/1.1[\r][\n]"
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (org.apache.http.wire)- >> "Accept: application/json[\r][\n]"
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (org.apache.http.wire)- >> "Content-Length: 181[\r][\n]"
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (org.apache.http.wire)- >> "Content-Type: application/json; charset=UTF-8[\r][\n]"
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (org.apache.http.wire)- >> "Host: 0.0.0.0:9644[\r][\n]"
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (org.apache.http.wire)- >> "Connection: Keep-Alive[\r][\n]"
2015-02-16 10:22:28,014 DEBUG https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20 (org.apache.http.wire)- >> "User-Agent: Apache-HttpClient/4.2.5 (java 1.5)[\r][\n]"

Can you check that your user password combination is correct?

What happened in the the wire logs just after this for thread

https://developer.jboss.org/ResourceContainer.invoker.availCheck.daemon-20?

However, for the thread where the auth fails I see this:

2015-02-16 10:31:17,051 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.conn.DefaultClientConnection)- Receiving response: HTTP/1.1 401 Unauthorized
2015-02-16 10:31:17,051 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.client.DefaultHttpClient)- Connection can be kept alive for 5000 MILLISECONDS
2015-02-16 10:31:17,051 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.client.DefaultHttpClient)- Authentication required
2015-02-16 10:31:17,051 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9644 requested authentication
2015-02-16 10:31:17,051 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.client.DefaultHttpClient)- Authorization challenge processed
2015-02-16 10:31:17,051 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.client.DefaultHttpClient)- Authentication failed
2015-02-16 10:31:17,051 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.conn.DefaultClientConnection)- Connection 0.0.0.0:45809<->10.49.67.52:9644 shut down
2015-02-16 10:31:17,051 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.conn.DefaultClientConnection)- Connection 0.0.0.0:45809<->10.49.67.52:9644 closed
2015-02-16 10:31:17,052 DEBUG https://developer.jboss.org/ResourceContainer.invoker.daemon-1562 (apache.http.impl.conn.PoolingClientConnectionManager)- Connection released: id: 93306[route: ->https://0.0.0.0:9644][total kept alive: 0; route allocated: 0 of 10; total allocated: 0 of 10]
2015-02-16 10:31:17,052 WARN https://developer.jboss.org/ConfigurationManager.threadpool-1 (rhq.core.pc.configuration.ConfigurationCheckExecutor)- An error occurred while checking for an updated Resource configuration for Resource[id=12139, uuid=2442eeed-0f1d-4048-b4de-06fd5d334e37, type=SocketBindingGroup, key=socket-binding-group=standard-sockets, name=standard-sockets, parent=Stilling-solr (9644)].
org.rhq.core.pluginapi.inventory.InvalidPluginConfigurationException: Credentials for plugin to connect to AS7 management interface are invalid - update Connection Settings with valid credentials.
at org.rhq.modules.plugins.jbossas7.ASConnection.executeRaw(ASConnection.java:304)

So it does not even enter "TargetAuthenticationStrategy" negotiation at all?

You have no wire logs between those two events? What happened before for

thread https://developer.jboss.org/ResourceContainer.invoker.daemon-1562?

Also, just an instant before the second request fails I see this:

*2015-02-16 10:31:16,951 DEBUG https://developer.jboss.org/ASConnection Cleaner
(apache.http.impl.conn.PoolingClientConnectionManager)- Closing expired
connections*

*2015-02-16 10:31:16,951 DEBUG https://developer.jboss.org/ASConnection Cleaner
(apache.http.impl.conn.PoolingClientConnectionManager)- Closing
connections idle longer than 5000 MILLISECONDS*

Could this be related, the connection cleaner closing the connection
right before the second attempt?

I don't think so.

I have no idea why the file-based auth seems to work though, will keep
watching to see if I am able to catch any exception on this one server.

From what I see, I believe that there's an issue with the AD

integration with your AS7 server.

18. Re: Re: Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

pathduck Feb 16, 2015 6:08 AM (in response to tsegismont)

Ok Thomas, thanks - is there any way to get from basic digest to the password without brute force? These are servers behind firewalls and I feel pretty secure, but I still try to remove what I find of passwords.

I wish this was JON then I could attach logs to a support case without any worries.

>I believe that there's an issue with the AD integration with your AS7 server.

Mmm, maybe, but how do I enable some more logs on the management interface in Jboss? I have this:

</logger>

This does not seem to log anything relating to management-interface however...

It just seems to me that "TargetAuthenticationStrategy" just does not get entered at times and then the InvalidPluginConfigurationException gets thrown.

> What happened in the the wire logs just after this for thread

Nothing, really - it just starts to authenticate (and succeed) to another server:

2015-02-16 10:31:17,233 INFO  [ResourceContainer.invoker.daemon-1562] (rhq.modules.plugins.jbossas7.ASConnection)- JSON to send: {"operation":"read-attribute","address":[{"deployment":"nav-sbl-arbeid-j2ee-4.2.14.2.ear"},{"subdeployment":"nav-sbl-arbeid-ejb.jar"},{"subsystem":"ejb3"},{"stateless-session-bean":"StatusChangeBO"}],"name":"invocations"}
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.PoolingClientConnectionManager)- Connection request: [route: {}->http://0.0.0.0:9990][total kept alive: 1; route allocated: 1 of 10; total allocated: 1 of 10]
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.PoolingClientConnectionManager)- Connection leased: [id: 93292][route: {}->http://0.0.0.0:9990][total kept alive: 0; route allocated: 1 of 10; total allocated: 1 of 10]
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.client.protocol.RequestAddCookies)- CookieSpec selected: best-match
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.client.protocol.RequestAuthCache)- Auth cache not set in the context
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.client.protocol.RequestTargetAuthentication)- Target auth state: UNCHALLENGED
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.client.protocol.RequestProxyAuthentication)- Proxy auth state: UNCHALLENGED
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- Attempt 1 to execute request
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.DefaultClientConnection)- Sending request: POST /management HTTP/1.1
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "POST /management HTTP/1.1[\r][\n]"
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "Accept: application/json[\r][\n]"
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "Content-Length: 221[\r][\n]"
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "Content-Type: application/json; charset=UTF-8[\r][\n]"
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "Host: 0.0.0.0:9990[\r][\n]"
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "Connection: Keep-Alive[\r][\n]"
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "User-Agent: Apache-HttpClient/4.2.5 (java 1.5)[\r][\n]"
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "[\r][\n]"
2015-02-16 10:31:17,233 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- >> "{"operation":"read-attribute","address":[{"deployment":"nav-sbl-arbeid-j2ee-4.2.14.2.ear"},{"subdeployment":"nav-sbl-arbeid-ejb.jar"},{"subsystem":"ejb3"},{"stateless-session-bean":"StatusChangeBO"}],"name":"invocations"}"
2015-02-16 10:31:17,234 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "HTTP/1.1 200 OK[\r][\n]"
2015-02-16 10:31:17,234 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "Transfer-encoding: chunked[\r][\n]"
2015-02-16 10:31:17,234 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "Content-type: application/json[\r][\n]"
2015-02-16 10:31:17,234 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "Date: Mon, 16 Feb 2015 09:31:17 GMT[\r][\n]"
2015-02-16 10:31:17,234 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 10:31:17,234 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.DefaultClientConnection)- Receiving response: HTTP/1.1 200 OK
2015-02-16 10:31:17,234 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- Connection can be kept alive for 5000 MILLISECONDS
2015-02-16 10:31:17,234 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "25[\r][\n]"
2015-02-16 10:31:17,235 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "{"outcome" : "success", "result" : 0}"
2015-02-16 10:31:17,235 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 10:31:17,235 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "0[\r][\n]"
2015-02-16 10:31:17,235 DEBUG [ResourceContainer.invoker.daemon-1562] (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 10:31:17,235 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.PoolingClientConnectionManager)- Connection [id: 93292][route: {}->http://0.0.0.0:9990] can be kept alive for 5000 MILLISECONDS
2015-02-16 10:31:17,235 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.conn.PoolingClientConnectionManager)- Connection released: [id: 93292][route: {}->http://0.0.0.0:9990][total kept alive: 1; route allocated: 1 of 10; total allocated: 1 of 10]
2015-02-16 10:31:17,235 INFO  [ResourceContainer.invoker.daemon-1562] (rhq.modules.plugins.jbossas7.ASConnection)- {
  "outcome" : "success",
  "result" : 0
}

I think what is strange is what happens here:

2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9644 requested authentication
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- Authorization challenge processed
2015-02-16 10:31:17,051 DEBUG [ResourceContainer.invoker.daemon-1562] (apache.http.impl.client.DefaultHttpClient)- Authentication failed

Why does it not even try to enter the negotiation for auth schemes?

19. Re: Re: Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

tsegismont Feb 16, 2015 6:21 AM (in response to pathduck)

Le 16/02/2015 12:08, Stian Lund a écrit :

Ok Thomas, thanks - is there any way to get from basic digest to the
password without brute force? These are servers behind firewalls and I
feel pretty secure, but I still try to remove what I find of passwords.

Absolutely, in basic auth, the client sends the "user:password" string,

base64 encoded.

On Linux, something simple as this will give you the "user:password" string:

echo xyz123456xyz= | base64 -d

I wish this was JON then I could attach logs to a support case without
any worries.

>I believe that there's an issue with the AD integration with your AS7
server.

Mmm, maybe, but how do I enable some more logs on the management
interface in Jboss? I have this:

<logger category="org.jboss.security">

<level name="DEBUG"/>
</logger>

This does not seem to log anything relating to management-interface
however...

I'm not sure, as I said. Perhaps can you ask on the Wildfly forum?

It just seems to me that "TargetAuthenticationStrategy" just does not
get entered at times and then the InvalidPluginConfigurationException
gets thrown.

> What happened in the the wire logs just after this for thread

Nothing, really - it just starts to authenticate (and succeed) to
another server:

Indeed

2015-02-16 10:31:17,233 INFO (rhq.modules.plugins.jbossas7.ASConnection)- JSON to send: {"operation":"read-attribute","address":[{"deployment":"nav-sbl-arbeid-j2ee-4.2.14.2.ear"},{"subdeployment":"nav-sbl-arbeid-ejb.jar"},{"subsystem":"ejb3"},{"stateless-session-bean":"StatusChangeBO"}],"name":"invocations"}
2015-02-16 10:31:17,233 DEBUG (apache.http.impl.conn.PoolingClientConnectionManager)- Connection request: route: {}->http://0.0.0.0:9990[total kept alive: 1; route allocated: 1 of 10; total allocated: 1 of 10]
2015-02-16 10:31:17,233 DEBUG (apache.http.impl.conn.PoolingClientConnectionManager)- Connection leased: id: 93292[route: {}->http://0.0.0.0:9990][total kept alive: 0; route allocated: 1 of 10; total allocated: 1 of 10]
2015-02-16 10:31:17,233 DEBUG (apache.http.client.protocol.RequestAddCookies)- CookieSpec selected: best-match
2015-02-16 10:31:17,233 DEBUG (apache.http.client.protocol.RequestAuthCache)- Auth cache not set in the context
2015-02-16 10:31:17,233 DEBUG (apache.http.client.protocol.RequestTargetAuthentication)- Target auth state: UNCHALLENGED
2015-02-16 10:31:17,233 DEBUG (apache.http.client.protocol.RequestProxyAuthentication)- Proxy auth state: UNCHALLENGED
2015-02-16 10:31:17,233 DEBUG (apache.http.impl.client.DefaultHttpClient)- Attempt 1 to execute request
2015-02-16 10:31:17,233 DEBUG (apache.http.impl.conn.DefaultClientConnection)- Sending request: POST /management HTTP/1.1
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "POST /management HTTP/1.1[\r][\n]"
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "Accept: application/json[\r][\n]"
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "Content-Length: 221[\r][\n]"
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "Content-Type: application/json; charset=UTF-8[\r][\n]"
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "Host: 0.0.0.0:9990[\r][\n]"
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "Connection: Keep-Alive[\r][\n]"
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "User-Agent: Apache-HttpClient/4.2.5 (java 1.5)[\r][\n]"
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "[\r][\n]"
2015-02-16 10:31:17,233 DEBUG (org.apache.http.wire)- >> "{"operation":"read-attribute","address":[{"deployment":"nav-sbl-arbeid-j2ee-4.2.14.2.ear"},{"subdeployment":"nav-sbl-arbeid-ejb.jar"},{"subsystem":"ejb3"},{"stateless-session-bean":"StatusChangeBO"}],"name":"invocations"}"
2015-02-16 10:31:17,234 DEBUG (org.apache.http.wire)- << "HTTP/1.1 200 OK[\r][\n]"
2015-02-16 10:31:17,234 DEBUG (org.apache.http.wire)- << "Transfer-encoding: chunked[\r][\n]"
2015-02-16 10:31:17,234 DEBUG (org.apache.http.wire)- << "Content-type: application/json[\r][\n]"
2015-02-16 10:31:17,234 DEBUG (org.apache.http.wire)- << "Date: Mon, 16 Feb 2015 09:31:17 GMT[\r][\n]"
2015-02-16 10:31:17,234 DEBUG (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 10:31:17,234 DEBUG (apache.http.impl.conn.DefaultClientConnection)- Receiving response: HTTP/1.1 200 OK
2015-02-16 10:31:17,234 DEBUG (apache.http.impl.client.DefaultHttpClient)- Connection can be kept alive for 5000 MILLISECONDS
2015-02-16 10:31:17,234 DEBUG (org.apache.http.wire)- << "25[\r][\n]"
2015-02-16 10:31:17,235 DEBUG (org.apache.http.wire)- << "{"outcome" : "success", "result" : 0}"
2015-02-16 10:31:17,235 DEBUG (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 10:31:17,235 DEBUG (org.apache.http.wire)- << "0[\r][\n]"
2015-02-16 10:31:17,235 DEBUG (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 10:31:17,235 DEBUG (apache.http.impl.conn.PoolingClientConnectionManager)- Connection id: 93292[route: {}->http://0.0.0.0:9990] can be kept alive for 5000 MILLISECONDS
2015-02-16 10:31:17,235 DEBUG (apache.http.impl.conn.PoolingClientConnectionManager)- Connection released: id: 93292[route: {}->http://0.0.0.0:9990][total kept alive: 1; route allocated: 1 of 10; total allocated: 1 of 10]
2015-02-16 10:31:17,235 INFO (rhq.modules.plugins.jbossas7.ASConnection)- {
"outcome" : "success",
"result" : 0
}

I think what is strange is what happens here:

2015-02-16 10:31:17,051 DEBUG (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9644 requested authentication
2015-02-16 10:31:17,051 DEBUG (apache.http.impl.client.DefaultHttpClient)- Authorization challenge processed
2015-02-16 10:31:17,051 DEBUG (apache.http.impl.client.DefaultHttpClient)- Authentication failed

Why does it not even try to enter the negotiation for auth schemes?

Is this last log snippet isolated? It should be part of a larger http

exchange.

20. Re: Re: Re: Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

pathduck Feb 16, 2015 6:47 AM (in response to tsegismont)

> Is this last log snippet isolated? It should be part of a larger http exchange.

It's basically just this:

2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.DefaultHttpClient)- Attempt 2 to execute request
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.conn.DefaultClientConnection)- Sending request: POST /management HTTP/1.1
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "POST /management HTTP/1.1[\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Accept: application/json[\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Content-Length: 134[\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Content-Type: application/json; charset=UTF-8[\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Host: 0.0.0.0:9943[\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Connection: Keep-Alive[\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "User-Agent: Apache-HttpClient/4.2.5 (java 1.5)[\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Authorization: Basic [\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "[\r][\n]"
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "{"operation":"read-resource","address":[{"subsystem":"mail"}],"attribut
es-only":true,"include-runtime":false,"include-defaults":false}"
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (org.apache.http.wire)- << "HTTP/1.1 401 Unauthorized[\r][\n]"
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (org.apache.http.wire)- << "Content-length: 0[\r][\n]"
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (org.apache.http.wire)- << "Www-authenticate: Basic realm="ManagementRealm"[\r][\n]"
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (org.apache.http.wire)- << "Date: Mon, 16 Feb 2015 11:20:07 GMT[\r][\n]"
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.conn.DefaultClientConnection)- Receiving response: HTTP/1.1 401 Unauthorized
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.client.DefaultHttpClient)- Connection can be kept alive for 5000 MILLISECONDS
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.client.DefaultHttpClient)- Authentication required
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9943 requested authentication
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.client.DefaultHttpClient)- Authorization challenge processed
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.client.DefaultHttpClient)- Authentication failed
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.conn.DefaultClientConnection)- Connection 0.0.0.0:37191<->10.49.67.52:9943 shut down
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.conn.DefaultClientConnection)- Connection 0.0.0.0:37191<->10.49.67.52:9943 closed
2015-02-16 12:20:07,552 DEBUG [ResourceContainer.invoker.availCheck.daemon-85] (apache.http.impl.conn.PoolingClientConnectionManager)- Connection released: [id: 95787][route: {s}->https://0.0.0.0:9943][total kept alive: 1; route allocated: 2 of 10; total allocated: 2 of 10]

So what happens between "challenge processed" and "authentication failed" ?

21. Re: Re: Re: Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

tsegismont Feb 16, 2015 8:13 AM (in response to pathduck)

Le 16/02/2015 12:49, Stian Lund a écrit :

> Is this last log snippet isolated? It should be part of a larger http
exchange.

It's basically just this:

2015-02-16 12:20:07,460 DEBUG (apache.http.impl.client.DefaultHttpClient)- Attempt 2 to execute request
2015-02-16 12:20:07,460 DEBUG (apache.http.impl.conn.DefaultClientConnection)- Sending request: POST /management HTTP/1.1
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "POST /management HTTP/1.1[\r][\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "Accept: application/json[\r][\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "Content-Length: 134[\r][\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "Content-Type: application/json; charset=UTF-8[\r][\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "Host: 0.0.0.0:9943[\r][\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "Connection: Keep-Alive[\r][\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "User-Agent: Apache-HttpClient/4.2.5 (java 1.5)[\r][\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "Authorization: Basic [\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "[\r][\n]"
2015-02-16 12:20:07,460 DEBUG (org.apache.http.wire)- >> "{"operation":"read-resource","address":[{"subsystem":"mail"}],"attribut
es-only":true,"include-runtime":false,"include-defaults":false}"
2015-02-16 12:20:07,552 DEBUG (org.apache.http.wire)- << "HTTP/1.1 401 Unauthorized[\r][\n]"
2015-02-16 12:20:07,552 DEBUG (org.apache.http.wire)- << "Content-length: 0[\r][\n]"
2015-02-16 12:20:07,552 DEBUG (org.apache.http.wire)- << "Www-authenticate: Basic realm="ManagementRealm"[\r][\n]"
2015-02-16 12:20:07,552 DEBUG (org.apache.http.wire)- << "Date: Mon, 16 Feb 2015 11:20:07 GMT[\r][\n]"
2015-02-16 12:20:07,552 DEBUG (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.conn.DefaultClientConnection)- Receiving response: HTTP/1.1 401 Unauthorized
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.client.DefaultHttpClient)- Connection can be kept alive for 5000 MILLISECONDS
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.client.DefaultHttpClient)- Authentication required
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9943 requested authentication
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.client.DefaultHttpClient)- Authorization challenge processed
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.client.DefaultHttpClient)- Authentication failed
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.conn.DefaultClientConnection)- Connection 0.0.0.0:37191<->10.49.67.52:9943 shut down
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.conn.DefaultClientConnection)- Connection 0.0.0.0:37191<->10.49.67.52:9943 closed
2015-02-16 12:20:07,552 DEBUG (apache.http.impl.conn.PoolingClientConnectionManager)- Connection released: id: 95787[route: ->https://0.0.0.0:9943][total kept alive: 1; route allocated: 2 of 10; total allocated: 2 of 10]

So what happens between "challenge processed" and "authentication failed" ?

Nothing (confirmed looking at HTTPClient source code).

The key message here is "Attempt 2 to execute request". It means that

HTTPClient already tried to answer the challenge. You should have some

logs a bit earlier for thread

22. Re: Re: Re: Re: Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

pathduck Feb 16, 2015 8:35 AM (in response to tsegismont)

Here's Attempt 1:

2015-02-16 12:20:07,459 INFO  [ResourceContainer.invoker.availCheck.daemon-25] (rhq.modules.plugins.jbossas7.ASConnection)- JSON to send: {"operation":"read-resource","address":[{"subsystem":"mail"}],"attributes-only":true,"include-runtime":false,"include-defaults":false}
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.conn.PoolingClientConnectionManager)- Connection request: [route: {s}->https://0.0.0.0:9943][total kept alive: 2; route allocated: 3 of 10; total allocated: 3 of 10]
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.conn.PoolingClientConnectionManager)- Connection leased: [id: 95791][route: {s}->https://0.0.0.0:9943][total kept alive: 1; route allocated: 3 of 10; total allocated: 3 of 10]
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestAddCookies)- CookieSpec selected: best-match
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestAuthCache)- Auth cache not set in the context
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestTargetAuthentication)- Target auth state: UNCHALLENGED
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestProxyAuthentication)- Proxy auth state: UNCHALLENGED
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.DefaultHttpClient)- Attempt 1 to execute request
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.conn.DefaultClientConnection)- Sending request: POST /management HTTP/1.1
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "POST /management HTTP/1.1[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Accept: application/json[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Content-Length: 134[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Content-Type: application/json; charset=UTF-8[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Host: 0.0.0.0:9943[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "Connection: Keep-Alive[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "User-Agent: Apache-HttpClient/4.2.5 (java 1.5)[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- >> "{"operation":"read-resource","address":[{"subsystem":"mail"}],"attributes-only":true,"include-runtime":false,"include-defaults":false}"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- << "HTTP/1.1 401 Unauthorized[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- << "Content-length: 0[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- << "Www-authenticate: Basic realm="ManagementRealm"[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- << "Date: Mon, 16 Feb 2015 11:20:07 GMT[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (org.apache.http.wire)- << "[\r][\n]"
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.conn.DefaultClientConnection)- Receiving response: HTTP/1.1 401 Unauthorized
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.DefaultHttpClient)- Connection can be kept alive for 5000 MILLISECONDS
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.DefaultHttpClient)- Authentication required
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.DefaultHttpClient)- 0.0.0.0:9943 requested authentication
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.TargetAuthenticationStrategy)- Authentication schemes in the order of preference: [negotiate, Kerberos, NTLM, Digest, Basic]
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for negotiate authentication scheme not available
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for Kerberos authentication scheme not available
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for NTLM authentication scheme not available
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.TargetAuthenticationStrategy)- Challenge for Digest authentication scheme not available
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.DefaultHttpClient)- Selected authentication options: [BASIC]
2015-02-16 12:20:07,459 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestAddCookies)- CookieSpec selected: best-match
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestAuthCache)- Auth cache not set in the context
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestTargetAuthentication)- Target auth state: CHALLENGED
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestTargetAuthentication)- Generating response to an authentication challenge using basic scheme
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.client.protocol.RequestProxyAuthentication)- Proxy auth state: UNCHALLENGED
2015-02-16 12:20:07,460 DEBUG [ResourceContainer.invoker.availCheck.daemon-25] (apache.http.impl.client.DefaultHttpClient)- Attempt 2 to execute request

...

Ok, it looks like it decided the auth. strategy to use in attempt 1? And then tries again with this auth (BASIC)?

And then (presumably) it fails to AD or somewhere in JbossAS... Should not httpClient log any reason why "Authentication failed" ?

I have been unable to enable debug-logs for the management interface in Jboss. org.jboss.security is does not include management it seems.

Stian

23. Re: Re: Re: Re: Re: Re: Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

tsegismont Feb 16, 2015 9:05 AM (in response to pathduck)

Le 16/02/2015 14:36, Stian Lund a écrit :

Ok, it looks like it decided the auth. strategy to use in attempt 1? And
then tries again with this auth (BASIC)?

as7plugin takes a connection: "Connection leased"

At this point, authentication mode is not known: "Target auth state:

UNCHALLENGED"

In attempt 1, the server replies "HTTP/1.1 401 Unauthorized" with header

""Www-authenticate: Basic"

HTTPClient then selects basic auth strategy: "Selected authentication

options: "

In attempt 2, as7 plugin tries again with user and password in headers

(I guess you removed the base64 encoded "user:password" string from the

snippet: https://developer.jboss.org/message/918896#918896)

In attempt 2, the server replies "HTTP/1.1 401 Unauthorized" with header

""Www-authenticate: Basic"

HTTPClient understands: "Authentication required"

But also remembers that it already did its job: "Authorization challenge

processed"

Hence: "Authentication failed"

And then (presumably) it fails to AD or somewhere in JbossAS... Should
not httpClient log any reason why "Authentication failed" ?

As you can see in the wire logs, there's not much information coming

from the server, just "HTTP/1.1 401 Unauthorized" with header

""Www-authenticate: Basic"

I have been unable to enable debug-logs for the management interface in
Jboss. org.jboss.security is does not include management it seems.

You should post something on the Wildfly forum. They probably know how

to get output for management realm authentication problem.

24. Re: Lots of InvalidPluginConfigurationException - AS7 plugin, RHQ 4.13.1?

pathduck Feb 17, 2015 5:02 AM (in response to tsegismont)

I got some help on the JbossAS7 forum - however it seems the management interface is very unwilling to log anything what's going on, even on TRACE.

I remember this being mentioned a long time ago, and maybe it's gotten better in Wildfly.

Anyway, to our problem, the BigIP guys have looked into things and see some inconsistencies in the way the system is set up, so they are looking into it. We might have found the source of the problem. Will keep you updated, thanks for your help so far!

Stian