[springboot] request 시 reject당하는 error log 확인 방법

Spring 로 개발하다보면 컨트롤러에 Request를 보내면서 파라미터가 제대로 파싱되는지, 파라미터가 누락되면 어떻게 되는지 확인해야 한다. 그런데 아무런 설정을 해놓지 않고 테스트를 하면 어떤이유로 컨트롤러가 호출되고 거절되는지, API가 제대로 호출되었는지 알 수 없을때가 있다. 가령 다음과 같은 예다

@RestController
public class TestController {

    @GetMapping("/test/get")
    public String testGet(@RequestParam(value = "text") String text) {
        System.out.println("/test/get text = " + text);
        return "testGet";
    }
}

/test/get API를 생성하고 text를 필수값으로 받게했다. 그리고 테스트를 작성하여 실행해보았더니 다음과 같이 의도한 에러가 발생했다.

@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
class TestControllerTestKakaoValid {

    @Autowired
    TestRestTemplate testRestTemplate;

    @Test
    @DisplayName("get parameter에 필수값 체크")
    void testGetTest() {
        // given
        String url = "/test/get";

        // when
        ResponseEntity<String> responseEntity = testRestTemplate.getForEntity(url, String.class);

        // then
        System.out.println("responseEntity = " + responseEntity);
    }
}

결과

responseEntity = <400,{"code":"PARAMETER_ERROR","message":"Required String parameter 'text' is not present"},[Content-Type:"application/json", Transfer-Encoding:"chunked", Date:"Mon, 27 Apr 2020 23:09:48 GMT", Connection:"close"]>

 

 

보면 400에러로 Bad Request 에러가 발생한걸 알 수 있고, 문구를 보면 Required String parameter 'text' is not present 문구로 해당 값이 없어서 발생한 에러임을 알 수 있다.

 

GET방식은 그나마 보기가 편한데 문제는 POST방식이다. 가령 회원가입을 예로 들어보자.

@ToString
@Getter
public class PostTestRequest {
    @NotEmpty
    private String name;
    private int age;
    private String address;
}

 

컨트롤러

@PostMapping("/test/post")
public String testPost(@RequestBody @Valid PostTestRequest request) {
    System.out.println("request = " + request);

    return "testPost";
}

 

테스트 작성

    @Test
    @DisplayName("post parameter에 필수값 체크")
    void testPostTest() {
        // given
        String url = "/test/post";
        HashMap params = new HashMap();
//        params.put("name", "아이유"); // 에러를 유발하기 위해 일부로 주석
        params.put("age", 25);
        params.put("address", "서울");

        // when
        ResponseEntity<String> entity = testRestTemplate.postForEntity(url, params, String.class);

        // then
        System.out.println("entity = " + entity);
    }

테스트를 하면 다음과 같은 에러가 발생한다

WARN 14100 --- [o-auto-1-exec-1] .w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.web.bind.MethodArgumentNotValidException: Validation failed for argument [0] in public java.lang.String kr.sample.demo.controller.TestController.testPost(kr.sample.demo.controller.PostTestRequest): [Field error in object 'postTestRequest' on field 'name': rejected value [null]; codes [NotEmpty.postTestRequest.name,NotEmpty.name,NotEmpty.java.lang.String,NotEmpty]; arguments [org.springframework.context.support.DefaultMessageSourceResolvable: codes [postTestRequest.name,name]; arguments []; default message [name]]; default message [반드시 값이 존재하고 길이 혹은 크기가 0보다 커야 합니다.]] ]
DEBUG 14100 --- [o-auto-1-exec-1] o.s.w.f.CommonsRequestLoggingFilter : After request [POST /test/post]
entity = <400,{"timestamp":"2020-04-27T23:22:29.961+0000","status":400,"error":"Bad Request","errors":[{"codes":["NotEmpty.postTestRequest.name","NotEmpty.name","NotEmpty.java.lang.String","NotEmpty"],"arguments":[{"codes":["postTestRequest.name","name"],"arguments":null,"defaultMessage":"name","code":"name"}],"defaultMessage":"반드시 값이 존재하고 길이 혹은 크기가 0보다 커야 합니다.","objectName":"postTestRequest","field":"name","rejectedValue":null,"bindingFailure":false,"code":"NotEmpty"}],"message":"Validation failed for object='postTestRequest'. Error count: 1","path":"/test/post"},[Content-Type:"application/json", Transfer-Encoding:"chunked", Date:"Mon, 27 Apr 2020 23:22:29 GMT", Connection:"close"]>

 

Spring에서 제공하는 기본 설정으로 인해 testPost를 호출하다가 name이 필수값임에도 값이 없음을 확인하고 reject 되었다.

 

또 한가지 생각해야 할 것은 지금 상황에서는 /test/post 라는 API를 호출할 것임을 명확히 알고 있었기 때문에 무엇을 호출하다 문제가 발생했는지 알 수 있었다. 그런데 개발서버에만 올라가도 한번에 여러개 API가 호출되기에 그중 무엇이 호출되다 에러가 나는지 햇갈릴 수 있다. 그때 다음 옵션을 쓰면 어떤 API를 호출하다 에러가 난지 알 수 있다.

logging.level.org.springframework.web.filter=debug

테스트를 다시한번 수행해보면 Before와 After 로그가 추가되었고, 어떤 API를 호출했었는지 알 수 있다.

DEBUG 14136 --- [o-auto-1-exec-1] o.s.w.f.CommonsRequestLoggingFilter      : Before request [POST /test/post]
WARN 14136 --- [o-auto-1-exec-1] .w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.web.bind.MethodArgumentNotValidException: Validation failed for argument [0] in public java.lang.String kr.sample.demo.controller.TestController.testPost(kr.sample.demo.controller.PostTestRequest): [Field error in object 'postTestRequest' on field 'name': rejected value [null]; codes [NotEmpty.postTestRequest.name,NotEmpty.name,NotEmpty.java.lang.String,NotEmpty]; arguments [org.springframework.context.support.DefaultMessageSourceResolvable: codes [postTestRequest.name,name]; arguments []; default message [name]]; default message [반드시 값이 존재하고 길이 혹은 크기가 0보다 커야 합니다.]] ]
DEBUG 14136 --- [o-auto-1-exec-1] o.s.w.f.CommonsRequestLoggingFilter      : After request [POST /test/post]
entity = <400,{"timestamp":"2020-04-27T23:31:18.984+0000","status":400,"error":"Bad Request","errors":[{"codes":["NotEmpty.postTestRequest.name","NotEmpty.name","NotEmpty.java.lang.String","NotEmpty"],"arguments":[{"codes":["postTestRequest.name","name"],"arguments":null,"defaultMessage":"name","code":"name"}],"defaultMessage":"반드시 값이 존재하고 길이 혹은 크기가 0보다 커야 합니다.","objectName":"postTestRequest","field":"name","rejectedValue":null,"bindingFailure":false,"code":"NotEmpty"}],"message":"Validation failed for object='postTestRequest'. Error count: 1","path":"/test/post"},[Content-Type:"application/json", Transfer-Encoding:"chunked", Date:"Mon, 27 Apr 2020 23:31:19 GMT", Connection:"close"]>

 

 

끝.