Spring - Log Http Request , Response
ปัญหาหนึ่งที่มักเจอเสมอเวลาติดต่อกับ Thrid party คืออีกฝั่งตอบ Error กลับมา ซึ่ง Error ที่ตอบกลับมานั้นถ้าโชคดีหน่อยเขาจะบอกรายละเอียดแน่ชัดมาเลยว่าเป็นที่อะไร แต่ในกรณีที่โชคไม่ดีหน่อยเพราะ API ที่เขาทำนั้นเขาทำแบบเร่ง หรือ เขามั่นใจว่าคุณจะทำการส่งข้อมูลที่ถูกต้องให้เขาเสมอ เมื่อเกิดการ Error ขึ้นเขาก็แค่บอกว่า Error กลับไป ไม่ได้บอกเป็นที่อะไร ซึ่งด้วยผลลัพธ์แบบนี้บอกเลยว่า “หัวร้อน” แน่นอนครับ และเมื่อเขาเป็น Thrid party คุณไม่ใช่เจ้านายเขา คุณไม่มีอำนาจใดๆมากพอไปสั่งเขาได้ (ผมเคยเห็นคนมีอำนาจมากพอสั่งหน่วยงานอื่นได้นะ ผมนี่อย่างว้าวกับคนนั้นมากเลย) ดังนั้นวิธีการที่คุณพอจะทำได้คือ เอา Request , Response ที่ในรอบนี้เกิดปัญหานั้น ส่งให้ Third party เพื่อให้เขาบอกว่ามันเกิดปัญหาจากอะไร
Source code
source code ทั้งหมดที่ใช้เป็นตัวอย่างสามารถดูได้ที่ https://github.com/surapong-taotiamton/spring-log-request-response
Spring Http request
สมมุติผมทำ API ที่รับ Request param แล้วยิงต่อไปดึงข้อมูลต่อที่ https://jsonplaceholder.typicode.com/ เพื่อจำลองการติดต่อกับ Thrid party โดยถ้าเราเขียน Code โดยใช้ Spring เราสามารถเขียน Code เพื่อดึงข้อมูลได้ประมาณนี้
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
| @RestController
public class TestThirdPartyController {
private static final Logger logger = LoggerFactory.getLogger(TestThirdPartyController.class);
@GetMapping("/todo/{id}")
public ToDoDto getToDo(
@PathVariable("id") String id
) {
String url = "https://jsonplaceholder.typicode.com/todos/" + id;
RestTemplate restTemplate = new RestTemplate();
ResponseEntity<ToDoDto> responseEntity = restTemplate.exchange(url, HttpMethod.GET, HttpEntity.EMPTY, ToDoDto.class);
return responseEntity.getBody();
}
}
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
package blog.surapong.example.logrequestresponse.api.dto;
import lombok.EqualsAndHashCode;
import lombok.Getter;
import lombok.Setter;
import lombok.ToString;
import lombok.experimental.Accessors;
@Getter
@Setter
@Accessors(chain = true)
@EqualsAndHashCode
@ToString
public class ToDoDto {
private Long userId;
private Long id;
private String title;
private Boolean completed;
}
|
โดย Code ไม่มีอะไรทำมากไปกว่าคือรับ Id จาก Path variable จากนั้นยิงต่อไปที่ https://jsonplaceholder.typicode.com/todos/ เพื่อเอา Response กลับมา ซึ่งเมื่อทดลองผ่านหน้าจอจะได้ดังภาพ
โอเคคราวนี้ถ้าเราใส่ id เป็น 3000 เราจะได้ Error ดังภาพ
คราวนี้ก็จะเกิด Error ขึ้นครับ คราวนี้ถ้าเราอยากจะทราบว่าเราส่ง Request Response อะไรไปให้ Third party บ้างเราก็ต้องเขียน Code เพิ่มขึ้นมาครับ ซึ่งมีคนแนะนำไว้แล้วซึ่งตามไปอ่านได้ที่ : https://www.baeldung.com/spring-resttemplate-logging เขาอธิบายวิธีการไว้หมดแล้ว
อ้าวแล้วจะเขียนทำไมวะ จริงๆคือด้วยความขี้เกียจของผมคือ ไม่อยากเขียนเองเลยไปหาต่อว่ามีใครเขียนอะไรแบบนี้ไว้แล้วบ้าง ซึ่งก็เจอครับ ซึ่งนั่นก็คือ zalando-logbook
ใช้ Zalando-Logbook ทำ Log Request Response
เพิ่ม Dependency ลงใน Pom
เพิ่ม Dependency ลงใน pom นะครับ
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
|
<dependencies>
<dependency>
<groupId>org.zalando</groupId>
<artifactId>logbook-spring-boot-starter</artifactId>
<version>2.6.2</version>
</dependency>
<dependency>
<groupId>org.zalando</groupId>
<artifactId>logbook-core</artifactId>
<version>2.6.2</version>
</dependency>
<dependency>
<groupId>org.zalando</groupId>
<artifactId>logbook-httpclient</artifactId>
<version>2.6.2</version>
</dependency>
</dependencies>
|
เพิ่ม Config ใน application.properties
เพิ่มค่า config เข้าไปใน application.properties ดังค่าด้านล่าง
1
| logging.level.org.zalando.logbook=TRACE
|
ทำการแก้ไขตรงส่วน Call Http requeset ไปที่ Third party
ในการเรียก Http request ไปหา Thrid party นั้นเราจะใช้ RestTemplate ของ Spring ซึ่งมันสามารถสร้าง Interceptor เข้าไปใน RestTemplate เพื่อ Log Request Response ได้ โดยถ้าอ่านตัวอย่างจาก baeldung เขาจะให้เรา Implement เอง แต่ของผมนั้นจะไปใช้ Lib ของ zalando ซึ่งทำให้การสร้าง RestTemplate ของผมจึงแยกมาเป็น Private method ดังด้านล่าง เพราะทุกครั้งที่ทำการ Config RestTemplate แบบนี้ทุกครั้ง เลยแยกออกมาเลยเพื่อจะได้ใช้ได้หลายที่
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
| private RestTemplate createRestTemplate() {
SimpleClientHttpRequestFactory simpleClientHttpRequestFactory = new SimpleClientHttpRequestFactory();
simpleClientHttpRequestFactory.setOutputStreaming(false);
ClientHttpRequestFactory factory =
new BufferingClientHttpRequestFactory(simpleClientHttpRequestFactory);
RestTemplate restTemplate = new RestTemplate(factory);
Logbook logbook = Logbook.create();
LogbookClientHttpRequestInterceptor interceptor = new LogbookClientHttpRequestInterceptor(logbook);
restTemplate.getInterceptors().add(interceptor);
return restTemplate;
}
|
อันนี้ส่วนที่เรียกใช้งาน โดยขอเพิ่มอีก Endpoint นึงเลยเพื่อง่ายในการดูความแตกต่าง
1
2
3
4
5
6
7
8
9
| @GetMapping("/todo/log/{id}")
public ToDoDto getToDoLog(
@PathVariable("id") String id
) {
String url = "https://jsonplaceholder.typicode.com/todos/" + id;
RestTemplate restTemplate = createRestTemplate();
ResponseEntity<ToDoDto> responseEntity = restTemplate.exchange(url, HttpMethod.GET, HttpEntity.EMPTY, ToDoDto.class);
return responseEntity.getBody();
}
|
มาดูผลลัพธ์กัน
เราลองเรียกใช้งาน API ผ่าน http://127.0.0.1:8080/todo/log/1 จะได้ผลลัพธ์ดังภาพ
คราวนี้ลองไปดูใน Console log ของ Server จะได้
ในภาพอาจจะเห็นไม่เต็มมาลองดู Log เต็มๆ จะได้ดังภาพ
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
| # ส่วนที่ยิงออกไปหา Thrid party
2564-05-16 14:05:18.680 TRACE 14560 --- [nio-8080-exec-1] org.zalando.logbook.Logbook : Outgoing Request: adf2666b770005ba
Remote: localhost
GET https://jsonplaceholder.typicode.com/todos/1 HTTP/1.1
Accept: application/json, application/*+json
Content-Length: 0
# ส่วนที่ได้ตอบกลับจาก Thrid party
2564-05-16 14:05:19.051 TRACE 14560 --- [nio-8080-exec-1] org.zalando.logbook.Logbook : Incoming Response: adf2666b770005ba
Duration: 366 ms
HTTP/1.1 200 OK
Accept-Ranges: bytes
Access-Control-Allow-Credentials: true
Age: 24883
alt-svc: h3-27=":443"; ma=86400, h3-28=":443"; ma=86400, h3-29=":443"; ma=86400
Cache-Control: max-age=43200
CF-Cache-Status: HIT
CF-RAY: 6502c1ca8e36cbe4-SIN
cf-request-id: 0a159772930000cbe44012e000000001
Connection: keep-alive
Content-Length: 83
Content-Type: application/json; charset=utf-8
Date: Sun, 16 May 2021 07:05:19 GMT
Etag: W/"53-hfEnumeNh6YirfjyjaujcOPPT+s"
Expect-CT: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
Expires: -1
NEL: {"report_to":"cf-nel","max_age":604800}
Pragma: no-cache
Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report?s=j1GrG6LPL61zeVNMq1b%2BvOiB%2FQgsoj9XZObn4GuEwHvo6tneWSaWQiD25XJildqvBj0eKheWN65tswB9%2Bw0UFhEDteZ4dqeSQJMZXDOyb4QfecfHQz1rihuTmQVd"}],"group":"cf-nel","max_age":604800}
Server: cloudflare
Vary: Origin, Accept-Encoding
Via: 1.1 vegur
X-Content-Type-Options: nosniff
X-Powered-By: Express
X-Ratelimit-Limit: 1000
X-Ratelimit-Remaining: 999
X-Ratelimit-Reset: 1620749436
{"userId":1,"id":1,"title":"delectus aut autem","completed":false}
|
ลองในกรณี Error กันบ้าง
คราวนี้มาลอง Test กรณี Error กันบ้าง โดยยิงไปที่ : http://127.0.0.1:8080/todo/log/3000
ซึ่งเมื่อไปดูใน Log แล้วจะได้ข้อความด้านล่าง ซึ่งเราจะเห็น Request Response โดยส่วน Response นั้นตอบกลับมาเป็น 404
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
|
# ส่วนที่ยิงออกไปหา Thrid party
2564-05-16 14:15:26.734 TRACE 14560 --- [nio-8080-exec-4] org.zalando.logbook.Logbook : Outgoing Request: ca08db405127d62b
Remote: localhost
GET https://jsonplaceholder.typicode.com/todos/3000 HTTP/1.1
Accept: application/json, application/*+json
Content-Length: 0
# ส่วนที่ได้ตอบกลับจาก Thrid party
2564-05-16 14:15:26.943 TRACE 14560 --- [nio-8080-exec-4] org.zalando.logbook.Logbook : Incoming Response: ca08db405127d62b
Duration: 207 ms
HTTP/1.1 404 Not Found
Access-Control-Allow-Credentials: true
Age: 4122
alt-svc: h3-27=":443"; ma=86400, h3-28=":443"; ma=86400, h3-29=":443"; ma=86400
Cache-Control: max-age=43200
CF-Cache-Status: HIT
CF-RAY: 6502d0a1f9dc5653-SIN
cf-request-id: 0a15a0b93b00005653f01d9000000001
Connection: keep-alive
Content-Length: 2
Content-Type: application/json; charset=utf-8
Date: Sun, 16 May 2021 07:15:27 GMT
Etag: W/"2-vyGp6PvFo4RvsFtPoIWeCReyIC8"
Expect-CT: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
Expires: -1
NEL: {"report_to":"cf-nel","max_age":604800}
Pragma: no-cache
Report-To: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report?s=Pe3fXWnj8LWKvbjsXIXnl4%2Fqz%2FXwCBt4qn7Nfhl9USShQUIRP0%2FCtDXkbKD0kV1uGdx56xFCCaCb0sDspaOm6uJi%2BYeM%2FmXbiBUkeY6E6Uh72Z7tLg8M%2FvF0CCBq"}],"group":"cf-nel","max_age":604800}
Server: cloudflare
Vary: Origin, Accept-Encoding
Via: 1.1 vegur
X-Content-Type-Options: nosniff
X-Powered-By: Express
X-Ratelimit-Limit: 1000
X-Ratelimit-Remaining: 999
X-Ratelimit-Reset: 1621145265
{}
|
สรุป
สำหรับตอนนี้เราก็ได้วิธีการ Log Http Request Response เวลายิงไป Third party ไปแล้วนะครับ โดยในตัวอย่างของผมยิงเป็น Method GET ฝั่งที่ยิงออกไปเลยไม่ค่อยตัว Body แต่หากคุณลองไปยิงด้วย Method อื่น เช่น PUT , POST คุณจะเห็นตัว Body ของ Http Request ด้วยครับ โดยในส่วนของ Logbook นั้นสามารถกำหนด Format ของ Log ที่ออกมาได้ และสามารถเลือกได้ว่าจะเอาสส่วนไหนของทั้ง Request และ Response มาแสดงได้ โดยสามารถอ่าน Config ได้ที่ https://github.com/zalando/logbook ครับ
เพลงประกอบการเขียน Code
เพลงเก่าแต่ความหมายเพลงไม่เคยเก่า พี่มอสพี่แคทนี่เขาเป็นอมตะกันเหรอครับ หน้าตายังกะสตาฟไว้