xetus-oss / freeipa-pwd-portal

An external self-service password portal for communicating with a FreeIPA instance
8 stars 6 forks source link

Problems with password reset #2

Closed MCPDanilovich closed 7 years ago

MCPDanilovich commented 7 years ago

Hello, Then i try to reset password for account i receive error: Failed to issue password reset email: unknown-exception Error from logs: 2017-07-20 11:25:58.273 [http-bio-443-exec-10] [10.8.10.22] INFO FreeIPARestService - Received reset request for user: odanilovich 2017-07-20 11:25:58.315 [http-bio-443-exec-10] [10.8.10.22] ERROR FreeIPARestService - Encountered error while building password reset request com.googlecode.jsonrpc4j.HttpException: stream is closed at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:157) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:118) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.xetus.iris.FreeIPAClient.invokeList(FreeIPAClient.groovy:110) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.iris.FreeIPAClient.userFind(FreeIPAClient.groovy:127) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.freeipa.pwdportal.FreeIPARestService.resetRequest(FreeIPARestService.groovy:267) ~[FreeIPARestService.class:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_111] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_111] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_111] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_111] at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:181) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:97) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:200) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:99) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:243) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:223) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:197) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:149) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:171) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:290) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:209) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at javax.servlet.http.HttpServlet.service(HttpServlet.java:646) [freeipa-pwd-portal.war:na] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:265) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) [urlrewritefilter-4.0.4.jar:4.0.4] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at ch.qos.logback.classic.helpers.MDCInsertingServletFilter.doFilter(MDCInsertingServletFilter.java:51) [logback-classic-1.1.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [freeipa-pwd-portal.war:na] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:612) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [freeipa-pwd-portal.war:na] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [freeipa-pwd-portal.war:na] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421) [freeipa-pwd-portal.war:na] at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070) [freeipa-pwd-portal.war:na] at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611) [freeipa-pwd-portal.war:na] at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:314) [freeipa-pwd-portal.war:na] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_111] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_111] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [freeipa-pwd-portal.war:na] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111] Caused by: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: com.googlecode.jsonrpc4j.NoCloseInputStream@5fb87d58; line: 1, column: 2] at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1702) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:558) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:456) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._handleUnexpectedValue(UTF8StreamJsonParser.java:2689) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._nextTokenNotInObject(UTF8StreamJsonParser.java:878) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.nextToken(UTF8StreamJsonParser.java:772) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3834) ~[jackson-databind-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3783) ~[jackson-databind-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2908) ~[jackson-databind-2.8.5.jar:2.8.5] at com.googlecode.jsonrpc4j.ReadContext.nextValue(ReadContext.java:25) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponseNode(JsonRpcClient.java:298) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.getValidResponse(JsonRpcClient.java:232) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponse(JsonRpcClient.java:182) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponse(JsonRpcClient.java:517) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:155) ~[jsonrpc4j-1.5.0.jar:1.5.0] ... 50 common frames omitted

tmeneau commented 7 years ago

From your stack trace it seems likely that the FreeIPA PWD Portal can't establish an authenticated Kerberos session with the FreeIPA instance, which is required for the password reset. If I'm correct about the Kerberos authentication failure, the content of the response you're getting will indicate inadequate permissions or needing an authenticated session. This is the line in the stack trace that tipped me off, since FreeIPA will respond with HTML content if there's no authenticated Kerberos session:

[freeipa-pwd-portal.war:na] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111] Caused by: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null')

Can you try again with debug logging enabled for the JsonRpcClient to confirm? Adding the following line to your /etc/freeipa-pwd-portal/logback.groovy file should do the trick:

logger("com.xetus", INFO, ["ROLLING_FILE"], false)
/* add this --> */ logger("com.googlecode.jsonrpc4j.JsonRpcClient", TRACE, ["ROLLING_FILE", false)

note: make sure to sanitize logs for private data before posting here

MCPDanilovich commented 7 years ago

I can't change this config because i run freeipa-pwd-portal in docker container. Then i restart docker container reCapture is enable. And i can send reset request

tmeneau commented 7 years ago

You should be able to persist modifications you make to the logging configuration using Docker volumes. If you're using the xetus-oss/docker-freeipa-pwd-portal you can do this by:

  1. Creating a directory called data that you'll mount into the container.
  2. Creating the following (pwd)/data/etc/freeipa-pwd-portal/logback.groovy file:
import ch.qos.logback.classic.encoder.PatternLayoutEncoder
import ch.qos.logback.core.rolling.FixedWindowRollingPolicy
import ch.qos.logback.core.rolling.RollingFileAppender
import ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy
import ch.qos.logback.core.status.OnConsoleStatusListener

import static ch.qos.logback.classic.Level.*

appender("ROLLING_FILE", RollingFileAppender) {
    file = "/var/log/freeipa-pwd-portal/application.log"
    encoder(PatternLayoutEncoder) {
      pattern = "%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{req.remoteHost}] %-5level %logger{0} - %msg%n"
    }
    triggeringPolicy(SizeBasedTriggeringPolicy) {
        maxFileSize = '10MB'
    }
    rollingPolicy(FixedWindowRollingPolicy) {
        fileNamePattern = "/var/log/freeipa-pwd-portal/application-%d{yyyyMMdd_hhmmss}.%i.gz"
        maxIndex = 10
    }
}

logger("org.apache.cxf.phase.PhaseInterceptorChain", ERROR)
logger("com.xetus", INFO, ["ROLLING_FILE"], false)
logger("com.googlecode.jsonrpc4j.JsonRpcClient", TRACE, ["ROLLING_FILE", false)
root(WARN, ["ROLLING_FILE"])
  1. Run your container, making sure to pass the -v $PWD/data:/data parameter to the Docker run command.

The README on the xetus-oss/docker-freeipa-pwd-portal github page has an example docker run command you can modify to suit your needs.

edit: it may not be obvious, but this works because the Dockerfile's init.bash script actually symlinks the mounted /data/etc/freeipa-pwd-portal directory to the container's /etc/freeipa-pwd-portal directory, and won't overwrite the logback.groovy file if it notices that it already exists.

MCPDanilovich commented 7 years ago

Config added: logger("org.apache.cxf.phase.PhaseInterceptorChain", ERROR) logger("com.xetus", INFO, ["ROLLING_FILE"], false) logger("com.googlecode.jsonrpc4j.JsonRpcClient", TRACE, ["ROLLING_FILE"], false) root(WARN, ["ROLLING_FILE"])

Then i start container and try to reset password:

2017-07-20 15:20:43.670 [http-bio-443-exec-8] [10.8.10.22] INFO FreeIPARestService - Received reset request for user: agolubev 2017-07-20 15:20:44.233 [http-bio-443-exec-8] [10.8.10.22] ERROR FreeIPARestService - Encountered error while building password reset request com.googlecode.jsonrpc4j.HttpException: stream is closed at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:157) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:118) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.xetus.iris.FreeIPAClient.invokeList(FreeIPAClient.groovy:110) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.iris.FreeIPAClient.userFind(FreeIPAClient.groovy:127) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.freeipa.pwdportal.FreeIPARestService.resetRequest(FreeIPARestService.groovy:267) ~[FreeIPARestService.class:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_111] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_111] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_111] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_111] at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:181) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:97) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:200) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:99) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:243) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:223) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:197) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:149) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:171) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:290) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:209) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at javax.servlet.http.HttpServlet.service(HttpServlet.java:646) [freeipa-pwd-portal.war:na] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:265) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) [urlrewritefilter-4.0.4.jar:4.0.4] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at ch.qos.logback.classic.helpers.MDCInsertingServletFilter.doFilter(MDCInsertingServletFilter.java:51) [logback-classic-1.1.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [freeipa-pwd-portal.war:na] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:612) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [freeipa-pwd-portal.war:na] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [freeipa-pwd-portal.war:na] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421) [freeipa-pwd-portal.war:na] at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070) [freeipa-pwd-portal.war:na] at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611) [freeipa-pwd-portal.war:na] at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [freeipa-pwd-portal.war:na] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_111] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_111] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [freeipa-pwd-portal.war:na] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111] Caused by: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: com.googlecode.jsonrpc4j.NoCloseInputStream@1e73f732; line: 1, column: 2] at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1702) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:558) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:456) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._handleUnexpectedValue(UTF8StreamJsonParser.java:2689) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._nextTokenNotInObject(UTF8StreamJsonParser.java:878) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.nextToken(UTF8StreamJsonParser.java:772) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3834) ~[jackson-databind-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3783) ~[jackson-databind-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2908) ~[jackson-databind-2.8.5.jar:2.8.5] at com.googlecode.jsonrpc4j.ReadContext.nextValue(ReadContext.java:25) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponseNode(JsonRpcClient.java:298) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.getValidResponse(JsonRpcClient.java:232) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponse(JsonRpcClient.java:182) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponse(JsonRpcClient.java:517) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:155) ~[jsonrpc4j-1.5.0.jar:1.5.0] ... 50 common frames omitted

MCPDanilovich commented 7 years ago

Docker container logs: Generating /etc/iris/krb5.conf Generating /etc/iris/jaas.conf Generating /etc/freeipa-pwd-portal/siteconfig.groovy Adding the FreeIPA instance's SSL certificate to the JRE keystore... Certificate was added to keystore No keystore was supplied with the password portal's certificate; generating a temporary one now... Starting the Free IPA Password Portal... Running out of /tmp/freeipapwdportal.443 Jul 20, 2017 3:19:29 PM org.apache.coyote.AbstractProtocol init INFO: Initializing ProtocolHandler ["http-bio-443"] Jul 20, 2017 3:19:29 PM org.apache.catalina.core.StandardService startInternal INFO: Starting service Tomcat Jul 20, 2017 3:19:29 PM org.apache.catalina.core.StandardEngine startInternal INFO: Starting Servlet Engine: Apache Tomcat/7.0.57 Jul 20, 2017 3:19:30 PM org.apache.catalina.startup.ContextConfig getDefaultWebXmlFragment INFO: No global web.xml found Jul 20, 2017 3:19:33 PM org.apache.catalina.core.ApplicationContext log INFO: No Spring WebApplicationInitializer types detected on classpath Jul 20, 2017 3:19:33 PM org.apache.catalina.core.ApplicationContext log INFO: Initializing Spring root WebApplicationContext Jul 20, 2017 3:19:33 PM org.springframework.web.context.ContextLoader initWebApplicationContext INFO: Root WebApplicationContext: initialization started Jul 20, 2017 3:19:33 PM org.springframework.web.context.support.GroovyWebApplicationContext prepareRefresh INFO: Refreshing Root WebApplicationContext: startup date [Thu Jul 20 15:19:33 UTC 2017]; root of context hierarchy Jul 20, 2017 3:19:35 PM org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor <init> INFO: JSR-330 'javax.inject.Inject' annotation found and supported for autowiring SLF4J: Class path contains multiple SLF4J bindings. SLF4J: Found binding in [jar:file:/tmp/freeipapwdportal.443/webapps/ROOT/WEB-INF/lib/logback-classic-1.1.2.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: Found binding in [jar:file:/tmp/freeipapwdportal.443/webapps/ROOT/WEB-INF/lib/slf4j-simple-1.7.5.jar!/org/slf4j/impl/StaticLoggerBinder.class] SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder] Intializing logback override from: /etc/freeipa-pwd-portal/logback.groovy Jul 20, 2017 3:19:36 PM org.springframework.web.context.ContextLoader initWebApplicationContext INFO: Root WebApplicationContext: initialization completed in 3219 ms Jul 20, 2017 3:19:36 PM org.apache.catalina.core.ApplicationContext log INFO: org.tuckey.web.filters.urlrewrite.UrlRewriteFilter INFO: loaded (conf ok) Jul 20, 2017 3:19:36 PM org.springframework.web.context.support.XmlWebApplicationContext prepareRefresh INFO: Refreshing Root WebApplicationContext: startup date [Thu Jul 20 15:19:36 UTC 2017]; parent: Root WebApplicationContext Jul 20, 2017 3:19:36 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions INFO: Loading XML bean definitions from class path resource [META-INF/cxf/cxf.xml] Jul 20, 2017 3:19:36 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions INFO: Loading XML bean definitions from URL [file:/tmp/freeipapwdportal.443/webapps/ROOT/WEB-INF/classes/cxf-servlet.xml] Jul 20, 2017 3:19:36 PM org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor <init> INFO: JSR-330 'javax.inject.Inject' annotation found and supported for autowiring Jul 20, 2017 3:19:37 PM org.apache.coyote.AbstractProtocol start INFO: Starting ProtocolHandler ["http-bio-443"]

tmeneau commented 7 years ago

Huh, odd that we're not seeing logs from the JsonRpcClient. A quick things to check:

  1. cat data/etc/freeipa-pwd-portal/logback.groovy to make sure your modifications weren't overwritten (they shouldn't have been);
  2. Remove the ["ROLLING_FILE"] parameter to the logging call; unless you modified other parts of the log configuration, this shouldn't have any effect (thanks for catching my typo, by the way);
  3. Just to test, would you try setting the com.xetus log configuration to TRACE as well:
logger("com.xetus", TRACE, false)

Just to knock out unknown vectors on my part, did you follow the pre-requisite steps outlined here?

tmeneau commented 7 years ago

Ahh, sorry about that, I meant the steps outlined in the freeipa-pwd-portal project's README! The Iris pre-requisites should be taken care of for you by the docker container's init script.

MCPDanilovich commented 7 years ago

I will start from point 3: points 1,2,3,4,5 from Pre-Requisites - FreeIPA Instance was completed. I didn't config point 6 because Portal should not reset passwords to administrators. Point 1: cat from /data inside container: logger("org.apache.cxf.phase.PhaseInterceptorChain", ERROR) logger("com.xetus", TRACE, ["ROLLING_FILE"], false) logger("com.googlecode.jsonrpc4j.JsonRpcClient", TRACE, ["ROLLING_FILE"], false) root(WARN, ["ROLLING_FILE"])

cat from /etc/freeipa-pwd-portal/: logger("org.apache.cxf.phase.PhaseInterceptorChain", ERROR) logger("com.xetus", TRACE, ["ROLLING_FILE"], false) logger("com.googlecode.jsonrpc4j.JsonRpcClient", TRACE, ["ROLLING_FILE"], false) root(WARN, ["ROLLING_FILE"])

Point 2: When i try delete it continer didnt start. logger("org.apache.cxf.phase.PhaseInterceptorChain", ERROR) logger("com.xetus", TRACE, false) logger("com.googlecode.jsonrpc4j.JsonRpcClient", TRACE, false) root(WARN)

tmeneau commented 7 years ago

Sorry about that, it's been a minute since I've done logback configurations. After refreshing my memory on the logback docs I think we want to stick to the ROLLING_FILE appender for now. Adding trace to com.xetus should give us more information, so we'll stick with that instead. I'm not sure if you're trimming your logback.groovy configuration for ease of reading, but please make sure you have the appender definition in there, although theoretically the container should have failed to start if you didn't:

import ch.qos.logback.classic.encoder.PatternLayoutEncoder
import ch.qos.logback.core.rolling.FixedWindowRollingPolicy
import ch.qos.logback.core.rolling.RollingFileAppender
import ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy
import ch.qos.logback.core.status.OnConsoleStatusListener

import static ch.qos.logback.classic.Level.*

appender("ROLLING_FILE", RollingFileAppender) {
    file = "/var/log/freeipa-pwd-portal/application.log"
    encoder(PatternLayoutEncoder) {
      pattern = "%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{req.remoteHost}] %-5level %logger{0} - %msg%n"
    }
    triggeringPolicy(SizeBasedTriggeringPolicy) {
        maxFileSize = '10MB'
    }
    rollingPolicy(FixedWindowRollingPolicy) {
        fileNamePattern = "/var/log/freeipa-pwd-portal/application-%d{yyyyMMdd_hhmmss}.%i.gz"
        maxIndex = 10
    }
}

logger("org.apache.cxf.phase.PhaseInterceptorChain", ERROR)
logger("com.xetus", TRACE, ["ROLLING_FILE"])
logger("com.googlecode.jsonrpc4j.JsonRpcClient", TRACE, ["ROLLING_FILE"])
root(WARN, ["ROLLING_FILE"])

As for not modifying the LDAP server, I can't remember off the top of my head whether that's required even to change non-admin user passwords. I suspect it's not required since you should have given the service the User Administrator role, but let's see if we can get more information out of the logs before we check that out...

MCPDanilovich commented 7 years ago

My password server account in Freeipa has User Administrator permissions. I insert logback content `import ch.qos.logback.classic.encoder.PatternLayoutEncoder import ch.qos.logback.core.rolling.FixedWindowRollingPolicy import ch.qos.logback.core.rolling.RollingFileAppender import ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy import ch.qos.logback.core.status.OnConsoleStatusListener

import static ch.qos.logback.classic.Level.*

appender("ROLLING_FILE", RollingFileAppender) { file = "/var/log/freeipa-pwd-portal/application.log" encoder(PatternLayoutEncoder) { pattern = "%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{req.remoteHost}] %-5level %logger{0} - %msg%n" } triggeringPolicy(SizeBasedTriggeringPolicy) { maxFileSize = '10MB' } rollingPolicy(FixedWindowRollingPolicy) { fileNamePattern = "/var/log/freeipa-pwd-portal/application-%d{yyyyMMdd_hhmmss}.%i.gz" maxIndex = 10 } }

logger("org.apache.cxf.phase.PhaseInterceptorChain", ERROR) logger("com.xetus", TRACE, ["ROLLING_FILE"]) logger("com.googlecode.jsonrpc4j.JsonRpcClient", TRACE, ["ROLLING_FILE"]) root(WARN, ["ROLLING_FILE"])`

It is cat inside container's /etc/freeipa-pwd-portal/logback.groovy

Logs inside container: 2017-07-21 07:30:22.634 [http-bio-443-exec-1] [10.8.10.22] INFO FreeIPARestService - Received reset request for user: agolubev 2017-07-21 07:30:22.634 [http-bio-443-exec-1] [10.8.10.22] INFO FreeIPARestService - Received reset request for user: agolubev 2017-07-21 07:30:23.239 [http-bio-443-exec-1] [10.8.10.22] ERROR FreeIPARestService - Encountered error while building password reset request com.googlecode.jsonrpc4j.HttpException: stream is closed at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:157) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:118) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.xetus.iris.FreeIPAClient.invokeList(FreeIPAClient.groovy:110) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.iris.FreeIPAClient.userFind(FreeIPAClient.groovy:127) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.freeipa.pwdportal.FreeIPARestService.resetRequest(FreeIPARestService.groovy:267) ~[FreeIPARestService.class:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_111] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_111] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_111] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_111] at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:181) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:97) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:200) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:99) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:243) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:223) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:197) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:149) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:171) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:290) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:209) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at javax.servlet.http.HttpServlet.service(HttpServlet.java:646) [freeipa-pwd-portal.war:na] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:265) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) [urlrewritefilter-4.0.4.jar:4.0.4] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at ch.qos.logback.classic.helpers.MDCInsertingServletFilter.doFilter(MDCInsertingServletFilter.java:51) [logback-classic-1.1.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [freeipa-pwd-portal.war:na] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:612) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [freeipa-pwd-portal.war:na] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [freeipa-pwd-portal.war:na] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421) [freeipa-pwd-portal.war:na] at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070) [freeipa-pwd-portal.war:na] at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611) [freeipa-pwd-portal.war:na] at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [freeipa-pwd-portal.war:na] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_111] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_111] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [freeipa-pwd-portal.war:na] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111] Caused by: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: com.googlecode.jsonrpc4j.NoCloseInputStream@7757d27f; line: 1, column: 2] at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1702) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:558) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:456) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._handleUnexpectedValue(UTF8StreamJsonParser.java:2689) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._nextTokenNotInObject(UTF8StreamJsonParser.java:878) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.nextToken(UTF8StreamJsonParser.java:772) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3834) ~[jackson-databind-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3783) ~[jackson-databind-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2908) ~[jackson-databind-2.8.5.jar:2.8.5] at com.googlecode.jsonrpc4j.ReadContext.nextValue(ReadContext.java:25) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponseNode(JsonRpcClient.java:298) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.getValidResponse(JsonRpcClient.java:232) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponse(JsonRpcClient.java:182) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponse(JsonRpcClient.java:517) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:155) ~[jsonrpc4j-1.5.0.jar:1.5.0] ... 50 common frames omitted 2017-07-21 07:30:23.239 [http-bio-443-exec-1] [10.8.10.22] ERROR FreeIPARestService - Encountered error while building password reset request com.googlecode.jsonrpc4j.HttpException: stream is closed at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:157) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:118) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.xetus.iris.FreeIPAClient.invokeList(FreeIPAClient.groovy:110) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.iris.FreeIPAClient.userFind(FreeIPAClient.groovy:127) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.freeipa.pwdportal.FreeIPARestService.resetRequest(FreeIPARestService.groovy:267) ~[FreeIPARestService.class:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_111] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_111] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_111] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_111] at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:181) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:97) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:200) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:99) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:243) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:223) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:197) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:149) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:171) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:290) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:209) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at javax.servlet.http.HttpServlet.service(HttpServlet.java:646) [freeipa-pwd-portal.war:na] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:265) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) [urlrewritefilter-4.0.4.jar:4.0.4] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at ch.qos.logback.classic.helpers.MDCInsertingServletFilter.doFilter(MDCInsertingServletFilter.java:51) [logback-classic-1.1.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [freeipa-pwd-portal.war:na] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:612) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [freeipa-pwd-portal.war:na] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [freeipa-pwd-portal.war:na] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421) [freeipa-pwd-portal.war:na] at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070) [freeipa-pwd-portal.war:na] at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611) [freeipa-pwd-portal.war:na] at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [freeipa-pwd-portal.war:na] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_111] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_111] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [freeipa-pwd-portal.war:na] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111] Caused by: com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null') at [Source: com.googlecode.jsonrpc4j.NoCloseInputStream@7757d27f; line: 1, column: 2] at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1702) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:558) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:456) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._handleUnexpectedValue(UTF8StreamJsonParser.java:2689) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._nextTokenNotInObject(UTF8StreamJsonParser.java:878) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.nextToken(UTF8StreamJsonParser.java:772) ~[jackson-core-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3834) ~[jackson-databind-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3783) ~[jackson-databind-2.8.5.jar:2.8.5] at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2908) ~[jackson-databind-2.8.5.jar:2.8.5] at com.googlecode.jsonrpc4j.ReadContext.nextValue(ReadContext.java:25) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponseNode(JsonRpcClient.java:298) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.getValidResponse(JsonRpcClient.java:232) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponse(JsonRpcClient.java:182) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcClient.readResponse(JsonRpcClient.java:517) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:155) ~[jsonrpc4j-1.5.0.jar:1.5.0] ... 50 common frames omitted

tmeneau commented 7 years ago

Well, this is frustrating, sorry about that -- it looks like I misread the jsonrpc4j source, and I haven't been able to find a way yet to log the response for the initial reset workflow connection. Let's try some different things:

  1. When you try the password change workflow, does it succeed? What do you see in the logs?
  2. Have you verified the keytab will successfully authenticate with the FreeIPA instance?
  3. Have you checked the FreeIPA instance's logs?

If you need help figuring out how to verify the keytab, something like the following should help:

  1. Confirm the keytab works as expected by trying the following on the FreeIPA client, replacing FREEIPA.EXAMPLE.COM with your test FreeIPA instance, and TEST_USER and NEW_PASSWORD with a test account whose password can be changed for testing purposes:
    1. kinit -k -t /etc/iris/keytab
    2. curl -v  \
           -H "referer:https://FREEIPA.EXAMPLE.COM/ipa" \
           -H "Content-Type:application/json" \
           -H "Accept:applicaton/json"\
           --negotiate -u : \
           -k \
           -d  '{"method":"passwd","params":[["TEST_USER"], {"password": "NEW_PASSWORD"}],"id":0}' \
           -X POST https://FREEIPA.EXAMPLE.COM/ipa/json
  2. If the curl request succeeds with a "200" status, but the response fails with an "Insufficient credentials" message, go back through the instructions in step (1) and verify host/ and HTTP/pw-portal.example.com have the correct permissions. If the kinit fails or the curl fails with a 401 and doesn't renegotiate:
    1. verify the keytab has the expected credentials with the following command (from the client host): klist -k -t /etc/iris/keytab
    2. verify the host setup in the FreeIPA web UI has the correct IP address
    3. verify the FreeIPA server can talk to the client and vice-versa
    4. It seems really unlikely to me, but if all the above looks right it's possible you'll need to apply the ldif to the FreeIPA instance after all. Theoretically you should be able to modify the specific permissions granted to the service to suit your needs.
MCPDanilovich commented 7 years ago

Then i try to do kinit -k -t /etc/iris/keytab/password.domain.com.keytab i get error: kinit: Cannot determine realm for host (principal host/password.domain.com@)

krb5.conf content: `[logging] default = FILE:var/logs/krb5.log

[libdefaults] default_realm = DOMAIN.COM dns_lookup_realm = true dns_lookup_kdc = true ticket_lifetime = 24h forwardable = true

[realms] DOMAIN.COM = { kdc = ipa1.domain.com admin_server = ipa1.domain.com }

[domain_realm] domain.com = DOMAIN.COM`

klist -k /etc/iris/keytab/password.domain.com.keytab: `Keytab name: FILE:/etc/iris/keytab/password.domain.com.keytab KVNO Principal


2 host/password.domain.com@ITCAPITAL.IO 2 host/password.domain.com@ITCAPITAL.IO 1 HTTP/password.domain.com@ITCAPITAL.IO 1 HTTP/password.domain.com@ITCAPITAL.IO`

tmeneau commented 7 years ago

Sorry for the slow response. It looks like you're not authenticating with the expected principal. Verifying the following steps should get us over this hurdle:

  1. The Kerberos realm configured in your krb5.conf configuration file (DOMAIN.COM) doesn't match the realm to which your service definitions are registered (ITCAPITAL.IO). Does your IPA server have a default realm of DOMAIN.COM and a separate realm for ITCAPITAL.IO? If not, you'll want to set the FREEIPA_REALM environment variable to a value of "ITCAPITAL.IO".

  2. Does the following successfully authenticate:

    kinit -k -t /etc/iris/keytab/password.domain.com.keytab host/password.domain.com@ITCAPITAL.IO
  3. Can you tell me what you've been passing to the FREEIPA_PWD_PORTAL_PRINCIPAL environment variable? My guess is you'll want to pass host/password.domain.com@ITCAPITAL.IO, but that may not be significant based on the above two items.

  4. Just as a sanity check; it looks like you're placing your keytab in the shared data volume at {{ host_data_volume }}/etc/iris/keytab/password.domain.com.keytab and passing the KEYTAB environment variable as /etc/iris/keytab/password.domain.com.keytab, is that correct?

MCPDanilovich commented 7 years ago

sorry i forget change realm name. I want to mask my real domain. Hostname and realm name has the same suffix

MCPDanilovich commented 7 years ago

For understanding, my real config: kinit -k -t /etc/iris/keytab/password.domain.com.keytab kinit: Cannot determine realm for host (principal host/password.itcapital.io@) krb5.conf: [logging] default = FILE:var/logs/krb5.log

[libdefaults] default_realm = ITCAPITAL.IO dns_lookup_realm = true dns_lookup_kdc = true ticket_lifetime = 24h forwardable = true

[realms] ITCAPITAL.IO = { kdc = ipa1.itcapital.io admin_server = ipa1.itcapital.io }

[domain_realm] itcapital.io = ITCAPITAL.IO

Keytab name: FILE:/etc/iris/keytab/password.itcapital.io.keytab KVNO Principal


4 host/password.itcapital.io@ITCAPITAL.IO 4 host/password.itcapital.io@ITCAPITAL.IO 3 HTTP/password.itcapital.io@ITCAPITAL.IO 3 HTTP/password.itcapital.io@ITCAPITAL.IO

Docker run command: docker run -d \ --name fpp \ -h password.itcapital.io \ -p 443:443 \ -v /opt/passportal/data:/data \ -e SMTP_HOST="relay.itcapital.io" \ -e SMTP_PORT="25" \ -e SMTP_FROM="freeipa-pwd-portal@capital.com" \ -e FREEIPA_REALM="ITCAPITAL.IO" \ -e FREEIPA_HOSTNAME="ipa1.itcapital.io" \ -e FREEIPA_PWD_PORTAL_PRINCIPAL="host/password.itcapital.io@ITCAPITAL.IO" \ -e FREEIPA_SSL_CERT=/data/certificate.crt \ -e KEYTAB=/data/password.itcapital.io.keytab \ xetusoss/freeipa-pwd-portal

MCPDanilovich commented 7 years ago

env variables: HOSTNAME=password.itcapital.io TERM=xterm KEYTAB=/etc/iris/keytab/password.itcapital.io.keytab SMTP_PORT=25 CA_CERTIFICATES_JAVA_VERSION=20140324 PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin PWD=/ JAVA_HOME=/usr/lib/jvm/java-8-openjdk-amd64 LANG=C.UTF-8 FREEIPA_PWD_PORTAL_PRINCIPAL=host/password.itcapital.io@ITCAPITAL.IO JAVA_VERSION=8u111 SMTP_HOST=relay.itcapital.io FREEIPA_HOSTNAME=ipa1.itcapital.io FREEIPA_REALM=ITCAPITAL.IO SMTP_FROM=freeipa-pwd-portal@itcapital.io FREEIPA_SSL_CERT=/data/certificate.crt SHLVL=1 HOME=/root JAVA_DEBIANVERSION=8u111-b14-2~bpo8+1 =/usr/bin/printenv

tmeneau commented 7 years ago

Cool, thanks for confirming that you were sanitizing the outputs and for including all the configuration information; everything looks consistent, so let's do a quick test to make sure these configurations (and your keytab) match what you have configured in your FreeIPA instance.

Can you share the output when you run the below commands from within your freeipa-pwd-portal docker container?

#
# Install the kerberos client utilities into the docker container
#
apt-get update
apt-get install -y krb5-user

#
# Attempt to authenticate using your keytab and the generated `krb5.conf` configuration
#
KRB5_CONFIG=/etc/iris/krb5.conf kinit -kt /etc/iris/keytab/password.itcapital.io.keytab host/password.itcapital.io@ITCAPITAL.IO

#
# List the kerberos ticket (including authenticated principal) if the above successfully authenticated
#
klist

If the above works we'll know your keytab, principal, and Kerberos configurations are all correct, and that your docker container can successfully connect to your FreeIPA instance. If the above does not work we'll need to dig deeper based on the output from the kinit command.

MCPDanilovich commented 7 years ago

kinit -kt /etc/iris/keytab/password.itcapital.io.keytab host/password.itcapital.io@ITCAPITAL.IO kinit: Clients credentials have been revoked while getting initial credentials

kinit -kt /etc/iris/keytab/password.itcapital.io.keytab kinit: Cannot determine realm for host (principal host/password.itcapital.io@)

tmeneau commented 7 years ago

Sorry for the slow response, I'm trying to figure out how you're getting that response from authenticating with the keytab and the krb5 configuration. The error you're seeing indicates the principal account is locked out or disabled, but I'm struggling to reproduce account lockouts for service/host principals in FreeIPA (using FreeIPA version 4.4.4). Here's some relevant Kerberos documentation on this.

Regardless, it seems the account is locked and you need to unlock the account, and then retry the command from the password portal host from earlier to see if you can authenticate successfully:

KRB5_CONFIG=/etc/iris/krb5.conf kinit -kt /etc/iris/keytab/password.itcapital.io.keytab host/password.itcapital.io@ITCAPITAL.IO

If the above command authenticates successfully, try the password reset from the password portal again. Out of curiosity, is the principal you're using (host/password.itcapital.io@ITCAPITAL.IO) a user account?

MCPDanilovich commented 7 years ago

No, i use host account.

MCPDanilovich commented 7 years ago

KLIST from another host where i coppied keytab file: Ticket cache: KEYRING:persistent:0:0 Default principal: host/password.itcapital.io@ITCAPITAL.IO

Valid starting Expires Service principal 07/25/2017 21:16:33 07/26/2017 21:16:33 krbtgt/ITCAPITAL.IO@ITCAPITAL.IO

But when i run kinit in docker container i get error:

kinit: Clients credentials have been revoked while getting initial credentials

tmeneau commented 7 years ago

Huh, that's not behavior I'd expect to be possible barring some special FreeIPA configuration. I'm trying to see if there's such a thing as source-host keytab usage restrictions, but if can you confirm in the meant time:

  1. Are there any differences between the krb5.conf file being used by the two hosts (the one where the keytab authenticates and the pw-portal)? Please note that the KRB5_CONFIG=/path/to/krb5.conf line is required if you're using a krb5.conf file in a non-standard location.
  2. Can you paste the exact kinit commands you ran on both hosts and, if possible, both krb5.conf files?
tmeneau commented 7 years ago

@MCPDanilovich, just wanted to check in and see if you're still trying to get this working. I'd be happy to hop on a chat with you if are so that we can work more expeditiously together to get to the bottom of this. Let me know!

MCPDanilovich commented 7 years ago

krb5.conf from host: includedir /var/lib/sss/pubconf/krb5.include.d/

[libdefaults] default_realm = ITCAPITAL.IO dns_lookup_realm = false dns_lookup_kdc = false rdns = false ticket_lifetime = 24h forwardable = true udp_preference_limit = 0 default_ccache_name = KEYRING:persistent:%{uid}

[realms] ITCAPITAL.IO = { kdc = ipa1.itcapital.io:88 master_kdc = ipa1.itcapital.io:88 admin_server = ipa1.itcapital.io:749 default_domain = itcapital.io pkinit_anchors = FILE:/etc/ipa/ca.crt

}

[domain_realm] .itcapital.io = ITCAPITAL.IO itcapital.io = ITCAPITAL.IO

From container: [logging] default = FILE:var/logs/krb5.log

[libdefaults] default_realm = ITCAPITAL.IO dns_lookup_realm = true dns_lookup_kdc = true ticket_lifetime = 24h forwardable = true

[realms] ITCAPITAL.IO = { kdc = ipa1.itcapital.io admin_server = ipa1.itcapital.io }

[domain_realm] itcapital.io = ITCAPITAL.IO

MCPDanilovich commented 7 years ago

kinit stop working after i try to request reset password from PW portal

tmeneau commented 7 years ago

When you say:

kinit stop working after i try to request reset password from PW portal

do you mean kinit using the container's keytab, or using the host's keytab?

Also, is there a time you'd be free to hop in a chat room? I've created the following Gitter chat: https://gitter.im/xetus-oss-freeipa-pwd-portal/Lobby

MCPDanilovich commented 7 years ago

I reinstall docker host. Now kinit working good, but in logs i see different error: 2017-08-03 07:44:35.294 [http-bio-443-exec-7] [10.8.10.22] INFO FreeIPARestService - Received reset request for user: vyanov 2017-08-03 07:44:35.300 [http-bio-443-exec-7] [10.8.10.22] ERROR FreeIPARestService - Encountered error while building password reset request java.net.UnknownHostException: “ipa1.itcapital.io” at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:184) ~[na:1.8.0_111] at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.8.0_111] at java.net.Socket.connect(Socket.java:589) ~[na:1.8.0_111] at sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:668) ~[na:1.8.0_111] at sun.net.NetworkClient.doConnect(NetworkClient.java:175) ~[na:1.8.0_111] at sun.net.www.http.HttpClient.openServer(HttpClient.java:432) ~[na:1.8.0_111] at sun.net.www.http.HttpClient.openServer(HttpClient.java:527) ~[na:1.8.0_111] at sun.net.www.protocol.https.HttpsClient.(HttpsClient.java:264) ~[na:1.8.0_111] at sun.net.www.protocol.https.HttpsClient.New(HttpsClient.java:367) ~[na:1.8.0_111] at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.getNewHttpClient(AbstractDelegateHttpsURLConnection.java:191) ~[na:1.8.0_111] at sun.net.www.protocol.http.HttpURLConnection.plainConnect0(HttpURLConnection.java:1181) ~[na:1.8.0_111] at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:1032) ~[na:1.8.0_111] at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection.java:177) ~[na:1.8.0_111] at sun.net.www.protocol.https.HttpsURLConnectionImpl.connect(HttpsURLConnectionImpl.java:153) ~[na:1.8.0_111] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:138) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.googlecode.jsonrpc4j.JsonRpcHttpClient.invoke(JsonRpcHttpClient.java:118) ~[jsonrpc4j-1.5.0.jar:1.5.0] at com.xetus.iris.FreeIPAClient.invokeList(FreeIPAClient.groovy:110) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.iris.FreeIPAClient.userFind(FreeIPAClient.groovy:127) ~[iris-1.0-SNAPSHOT.jar:na] at com.xetus.freeipa.pwdportal.FreeIPARestService.resetRequest(FreeIPARestService.groovy:267) ~[FreeIPARestService.class:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_111] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_111] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_111] at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_111] at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:181) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:97) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:200) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:99) [cxf-rt-frontend-jaxrs-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) [cxf-core-3.0.2.jar:3.0.2] at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:243) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:223) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:197) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:149) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:171) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:290) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:209) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at javax.servlet.http.HttpServlet.service(HttpServlet.java:646) [freeipa-pwd-portal.war:na] at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:265) [cxf-rt-transports-http-3.0.2.jar:3.0.2] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) [urlrewritefilter-4.0.4.jar:4.0.4] at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) [urlrewritefilter-4.0.4.jar:4.0.4] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at ch.qos.logback.classic.helpers.MDCInsertingServletFilter.doFilter(MDCInsertingServletFilter.java:51) [logback-classic-1.1.2.jar:na] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) [freeipa-pwd-portal.war:na] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:612) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170) [freeipa-pwd-portal.war:na] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [freeipa-pwd-portal.war:na] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [freeipa-pwd-portal.war:na] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421) [freeipa-pwd-portal.war:na] at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070) [freeipa-pwd-portal.war:na] at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611) [freeipa-pwd-portal.war:na] at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [freeipa-pwd-portal.war:na] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_111] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_111] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [freeipa-pwd-portal.war:na] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111]

MCPDanilovich commented 7 years ago

You can close this task!!! It is working now

tmeneau commented 7 years ago

Great! Please create a new issue if you run into anything new!