2

After Upgrading Spring-Boot from 1.3.7.RELEASE to 1.4.0.RELEASE I get the issue, when calling my rest service by inbound-channel-adapter, it throws a HttpClientErrorException.

Configuration inbound-channel-adapter:

<int-http:inbound-channel-adapter
        channel="api_app_integration_request_channel" 
        supported-methods="PUT" 
        path="/process/ticket"
        request-payload-type="*.model.Ticket"
        header-mapper="headerMapper"
        error-channel="internal-client-rest-ticket-error-channel"
    >
        <int-http:request-mapping consumes="application/json" />
    </int-http:inbound-channel-adapter>

Restservice-Call:

private static final String URL = "http://localhost:8080/process/ticket";
public void openTicket(final Profile profile, final Ticket ticket) {
        final HttpHeaders headers = new HttpHeaders();
        headers.set(Profile.PROFILE, profile.toString());
        final HttpEntity<Ticket> entity = new HttpEntity<Ticket>(ticket, headers);
        template.exchange(URL, HttpMethod.PUT, entity, Ticket.class);
    }

Exception:

org.springframework.web.client.HttpClientErrorException: 403 null
    at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:91)
    at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:667)
    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:620)
    at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:580)
    at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:498)
    at *.client.rest.simulator.ProblemReporter.openTicket(ProblemReporter.java:28)
    at *.client.SassRestSimulatorApplication.lambda$0(SassRestSimulatorApplication.java:96)
    at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
    at java.util.stream.SliceOps$1$1.accept(SliceOps.java:204)
    at java.util.stream.StreamSpliterators$InfiniteSupplyingSpliterator$OfRef.tryAdvance(StreamSpliterators.java:1356)
    at java.util.stream.ReferencePipeline.forEachWithCancel(ReferencePipeline.java:126)
    at java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:498)
    at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:485)
    at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)
    at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
    at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
    at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
    at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418)
    at *.client.SassRestSimulatorApplication.executeApplication(SassRestSimulatorApplication.java:96)
    at *.client.SassRestSimulatorApplication.main(SassRestSimulatorApplication.java:47)

Debug-Output

2016-08-07 18:56:24.022 DEBUG 16288 --- [           main] o.s.web.client.RestTemplate              : Created PUT request for "http://localhost:8080/process/ticket"
2016-08-07 18:56:24.180 DEBUG 16288 --- [           main] o.s.web.client.RestTemplate              : Setting request Accept header to [application/json, application/*+json]
2016-08-07 18:56:24.223 DEBUG 16288 --- [           main] o.s.web.client.RestTemplate              : Writing [Ticket# 1: [SIDE1-BS1-SP1] [SIDE1-BS1-SP1] [emergency] [NEW] Urgend problem. Fix immediately or revenue will be lost!] using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@18918d70]
2016-08-07 18:56:24.331 DEBUG 16288 --- [           main] o.s.web.client.RestTemplate              : PUT request for "http://localhost:8080/process/ticket" resulted in 403 (null); invoking error handler

I tried int-http:inbound-gateway BUT with same result.

When accessing service directly via Postman I get an 403 - Access denied and no logging found:

enter image description here

I am little bit supried about access denied, I don't use any security framework.

Under Spring-Boot 1.3.7.RELEASE works fine:

Logging-Output:

2016-08-07 20:03:23.098 TRACE 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Bound request context to thread: org.apache.catalina.connector.RequestFacade@32818b2d
2016-08-07 20:03:23.098 DEBUG 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing PUT request for [/process/ticket]
2016-08-07 20:03:23.098 TRACE 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Testing handler map [org.springframework.web.servlet.handler.SimpleUrlHandlerMapping@23764bec] in DispatcherServlet with name 'dispatcherServlet'
2016-08-07 20:03:23.098 TRACE 9372 --- [nio-8080-exec-4] o.s.w.s.handler.SimpleUrlHandlerMapping  : No handler mapping found for [/process/ticket]
2016-08-07 20:03:23.098 TRACE 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Testing handler map [org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping@5fa0d972] in DispatcherServlet with name 'dispatcherServlet'
2016-08-07 20:03:23.098 DEBUG 9372 --- [nio-8080-exec-4] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /process/ticket
2016-08-07 20:03:23.098 DEBUG 9372 --- [nio-8080-exec-4] s.w.s.m.m.a.RequestMappingHandlerMapping : Did not find handler method for [/process/ticket]
2016-08-07 20:03:23.098 TRACE 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Testing handler map [org.springframework.integration.http.inbound.IntegrationRequestMappingHandlerMapping@64dfb31d] in DispatcherServlet with name 'dispatcherServlet'
2016-08-07 20:03:23.098 TRACE 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Testing handler adapter [org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter@35467187]
2016-08-07 20:03:23.098 TRACE 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Testing handler adapter [org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter@52466d8b]
2016-08-07 20:03:23.100 DEBUG 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2016-08-07 20:03:23.100 TRACE 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@32818b2d
2016-08-07 20:03:23.100 DEBUG 9372 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Successfully completed request
2016-08-07 20:03:23.119 DEBUG 9372 --- [ sassExecutor-1] o.s.web.client.RestTemplate              : Created PUT request for "http://localhost:8080/process/ticket"
2016-08-07 20:03:23.120 DEBUG 9372 --- [ sassExecutor-1] o.s.web.client.RestTemplate              : Writing [Ticket# 666: [SIDE1-BS1-SP1] ] as "application/json" using [org.springframework.http.converter.json.MappingJackson2HttpMessageConverter@4d3ce1c0]
2016-08-07 20:03:23.126 TRACE 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Bound request context to thread: org.apache.catalina.connector.RequestFacade@32818b2d
2016-08-07 20:03:23.127 DEBUG 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : DispatcherServlet with name 'dispatcherServlet' processing PUT request for [/process/ticket]
2016-08-07 20:03:23.128 TRACE 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Testing handler map [org.springframework.web.servlet.handler.SimpleUrlHandlerMapping@23764bec] in DispatcherServlet with name 'dispatcherServlet'
2016-08-07 20:03:23.128 TRACE 9372 --- [nio-8080-exec-5] o.s.w.s.handler.SimpleUrlHandlerMapping  : No handler mapping found for [/process/ticket]
2016-08-07 20:03:23.128 TRACE 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Testing handler map [org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping@5fa0d972] in DispatcherServlet with name 'dispatcherServlet'
2016-08-07 20:03:23.128 DEBUG 9372 --- [nio-8080-exec-5] s.w.s.m.m.a.RequestMappingHandlerMapping : Looking up handler method for path /process/ticket
2016-08-07 20:03:23.129 DEBUG 9372 --- [nio-8080-exec-5] s.w.s.m.m.a.RequestMappingHandlerMapping : Did not find handler method for [/process/ticket]
2016-08-07 20:03:23.129 TRACE 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Testing handler map [org.springframework.integration.http.inbound.IntegrationRequestMappingHandlerMapping@64dfb31d] in DispatcherServlet with name 'dispatcherServlet'
2016-08-07 20:03:23.129 TRACE 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Testing handler adapter [org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter@35467187]
2016-08-07 20:03:23.129 TRACE 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Testing handler adapter [org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter@52466d8b]
2016-08-07 20:03:23.130 DEBUG 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
2016-08-07 20:03:23.130 TRACE 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Cleared thread-bound request context: org.apache.catalina.connector.RequestFacade@32818b2d
2016-08-07 20:03:23.130 DEBUG 9372 --- [nio-8080-exec-5] o.s.web.servlet.DispatcherServlet        : Successfully completed request
2016-08-07 20:03:23.134 DEBUG 9372 --- [ sassExecutor-1] o.s.web.client.RestTemplate              : PUT request for "http://localhost:8080/process/ticket" resulted in 200 (OK)
Ticket# 666: [SIDE1-BS1-SP1] [SIDE1-BS1-SP1] [low] [DECRYPTED] Ich bin von Postman gesendet worden

====== EDIT =======

Under Spring Boot 1.4.0 I get following Debug-Informations when calling the rest service:

2016-08-08 19:21:35.382 DEBUG 8268 --- [nio-8080-exec-2] o.a.coyote.http11.Http11InputBuffer      : Received [PUT /process/ticket HTTP/1.1
Host: localhost:8080
Connection: keep-alive
Content-Length: 206
Cache-Control: no-cache
Origin: chrome-extension://fdmmgilgnpjigdojojpjoooidkmcomcm
User-Agent: Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/51.0.2704.103 Safari/537.36
profile: 192.168.56.102:10000
Content-Type: application/json
Accept: */*
Accept-Encoding: gzip, deflate, sdch
Accept-Language: de-DE,de;q=0.8,en-US;q=0.6,en;q=0.4

{"ticketId":666,"issueDateTime":"2016-06-27","description":"Ich bin von Postman gesendet worden","sender":"SIDE1-BS1-SP1","receiver":"SIDE1-BS1-SP1","priority":"low","secured":"NEW","mimeType":"text/plain"}]
2016-08-08 19:21:35.383 DEBUG 8268 --- [nio-8080-exec-2] o.a.c.authenticator.AuthenticatorBase    : Security checking request PUT /process/ticket
2016-08-08 19:21:35.383 DEBUG 8268 --- [nio-8080-exec-2] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2016-08-08 19:21:35.383 DEBUG 8268 --- [nio-8080-exec-2] o.a.c.authenticator.AuthenticatorBase    :  Not subject to any constraint
2016-08-08 19:21:35.383 DEBUG 8268 --- [nio-8080-exec-2] o.apache.catalina.core.StandardWrapper   :   Returning non-STM instance
2016-08-08 19:21:35.384 DEBUG 8268 --- [nio-8080-exec-2] o.apache.coyote.http11.Http11Processor   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@16ab5cb1:org.apache.tomcat.util.net.NioChannel@5a719bf2:java.nio.channels.SocketChannel[connected local=/0:0:0:0:0:0:0:1:8080 remote=/0:0:0:0:0:0:0:1:57863]], Status in: [OPEN_READ], State out: [OPEN]

Spring-Boot-Starter:

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-integration</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.integration</groupId>
            <artifactId>spring-integration-http</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.integration</groupId>
            <artifactId>spring-integration-stream</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-web</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-tomcat</artifactId>
            <scope>provided</scope>
        </dependency>

====

Example-Application:

Under Spring-Boot 1.3.7 Works, 1.4.0 Error like described. Dropboxlink: link

Michael Hegner
  • 5,555
  • 9
  • 38
  • 64
  • Look at the server side logs. If necessary, turn on DEBUG/TRACE logging and watch the path/endpoint mappings. – Gary Russell Aug 06 '16 at 21:14
  • Debug-Output added. What has been changed between 1.3.x and 1.4.x, that it works on 1.3, but not on 1.4? – Michael Hegner Aug 07 '16 at 16:58
  • For me it looks like that inbound-channel-adapter doesnt work correctly. First I don`t know, why I get a 403 (no use of security), on server side no logging, I cant call it through RestTemplate nor throught Postman. Switching back to Spring Boot 1.3.7 everything is fine. Same with inbound-gateway. :-( – Michael Hegner Aug 07 '16 at 18:48
  • Please, share similar `TRACE` logs from server when you are in the Boot 1.4, therefore Spring Integration 4.3. And yes: you can force Spring Integration version in your pom to the `4.2.9.RELEASE` to isolate the problem exactly in the Spring Integration if that. – Artem Bilan Aug 08 '16 at 13:11
  • Also compare the logs between 1.3 and 1.4 - it sounds like `SpringBootWebSecurityConfiguration` is being invoked somehow - perhaps via `@EnableWebSecurity`. – Gary Russell Aug 08 '16 at 13:23
  • Hey Gary, thanks for reply, I don't have any security implemented nor configured. @EnableWebSecurity is not found. – Michael Hegner Aug 08 '16 at 16:54
  • Hey Artem, if I force Spring-Integration 4.2.9 I get a NoClassDefFoundError: `java.lang.NoClassDefFoundError: org/springframework/web/servlet/mvc/method/annotation/RequestMappingHandlerMapping` I try to log with spring 1.4 (application.properties => `logging.level.root=TRACE`), but after startup and calling service via postman, I dont get any logging more. Only 403 from Server – Michael Hegner Aug 08 '16 at 17:13
  • Okay, I got a logging. I guess that could help, I did a new section EDIT in the question. – Michael Hegner Aug 08 '16 at 17:23
  • Please don`t hesitate if you need more informations. – Michael Hegner Aug 10 '16 at 06:14

1 Answers1

1

Well, since you have a Spring Boot there it really looks like the spring-security in classpath causes a Security auto-configuration (SecurityAutoConfiguration).

Try to switch on --debug option when you start the application and look into auto-configuration for the "security" word.

OTOH you showed the first logs for Tomcat, but they say nothing about the further process with DispatcherServlet.

Can we see those logs?

UPDATE

Thank you for sample application. Unfortunately that works for me:

:: Spring Boot ::        (v1.4.0.RELEASE)

2016-08-11 11:35:36.762  INFO 8636 --- [           main] com.example.RestSimulatorApplication     : Starting RestSimulatorApplication on HOME with PID 8636 (D:\SpringIO\Spring140IntegrationTest\target\classes started by abilan in D:\SpringIO\Spring140IntegrationTest)
...
'dispatcherServlet': initialization started
2016-08-11 11:35:39.694  INFO 8636 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : FrameworkServlet 'dispatcherServlet': initialization completed in 11 ms
Ticket# 1: [emergency] [NEW] Urgend problem. Fix immediately or revenue will be lost!
Ticket# 2: [medium] [NEW] There is an issue; take a look whenever you have time.
Ticket# 3: [emergency] [NEW] Urgend problem. Fix immediately or revenue will be lost!
Ticket# 4: [medium] [NEW] There is an issue; take a look whenever you have time.

I tried it on Windows and Mac with the same good results.

Maybe you have some Fire Wall on your machine with the rule do not allow requests with some header or something else?..

Artem Bilan
  • 113,505
  • 11
  • 91
  • 118
  • Hey Artem, under following link you can see the Autoconfiguration Report. I don`t have any security-library on classpath (pom.xml), fulltext search under eclipse with keyword security has no matches. Dropboxlink: https://www.dropbox.com/sh/la7ff5mwl4ga79k/AAAoS7Bj0b4tzeWNUZKoTOg-a?dl=0 – Michael Hegner Aug 10 '16 at 16:22
  • I also added logging when tomcat starts – Michael Hegner Aug 10 '16 at 16:40
  • Hm. That doesn't help. Sorry. I wonder if you can share some simple Spring Boot application to play from our side locally. – Artem Bilan Aug 10 '16 at 16:53
  • Hey Artem, thank you, I will try to write a small program to simulate that behaviour. – Michael Hegner Aug 10 '16 at 17:02
  • Example application added to dropbox. (Configured with 1.3.7, just try application, then switch to 1.4.0, doesnt work more) – Michael Hegner Aug 10 '16 at 18:29
  • Please, find an UPDATE in my answer. Without failure I can't help you. Sorry :-( – Artem Bilan Aug 11 '16 at 15:53
  • I can confirm it works for me too with boot 1.4 as well. `Ticket# 1: [low] [NEW] Some minor problems have been found.` – Gary Russell Aug 11 '16 at 16:20
  • 1
    Thank you very much for trying out the application. It was really surprising me BUT good to know, that it works. I deleted all my m2-repository and recreate it again, and now it works for me too. The error - 403-Access denied - was really missleading me and I didn`t expect that kind of issue. – Michael Hegner Aug 11 '16 at 16:35