Skip to content
This repository was archived by the owner on Aug 4, 2024. It is now read-only.
This repository was archived by the owner on Aug 4, 2024. It is now read-only.

Order gets saved even after Resilience4j Time Limiter timeout #24

@aamirxshaikh

Description

@aamirxshaikh

Description:

I'm encountering an issue where, despite the Resilience4j Time Limiter being applied to the placeOrder method in the OrderService class, the order is still getting saved after a timeout. I have checked my implementation, but I haven't been able to identify the root cause.

Expected Behavior:
The order should not be saved if a timeout occurs due to the Resilience4j Time Limiter.

Actual Behavior:
The order is still being saved even after the Time Limiter timeout.

Environment:

  • Spring Boot Version: 3.2.2
  • Resilience4j Version: 3.1.0
  • Java Version: 17

application.properties:

# Resilience4J Timeout Properties
resilience4j.timelimiter.metrics.enabled=true
resilience4j.timelimiter.instances.inventory.timeout-duration=3s
resilience4j.timelimiter.instances.inventory.cancel-running-future=true

OrderController:

@PostMapping
@CircuitBreaker(name = "inventory", fallbackMethod = "fallbackMethod")
@TimeLimiter(name = "inventory")
public CompletableFuture<String> placeOrder(@RequestBody OrderRequest orderRequest) {
  return CompletableFuture.supplyAsync(() ->
          orderService.placeOrder(orderRequest)
  );
}

InventoryService:

@SneakyThrows
@Transactional(readOnly = true)
public List<InventoryResponse> areItemsInStock(List<String> skuCodeList) {
    log.info("wait start");
    Thread.sleep(10000);
    log.info("wait end");

    return inventoryRepository.findBySkuCodeIn(skuCodeList).stream()
            .map(inventory ->
                    InventoryResponse.builder()
                            .skuCode(inventory.getSkuCode())
                            .isInStock(inventory.getQuantity() > 0)
                            .build())
            .toList();
}

Screenshots:

Screenshot from 2024-03-10 21-56-43

Screenshot from 2024-03-10 21-58-39

Logs:

2024-03-10T21:56:08.261+05:30 ERROR 10626 --- [order-service] [o-auto-1-exec-9] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] threw exception

java.util.concurrent.TimeoutException: TimeLimiter 'inventory' recorded a timeout exception.
	at io.github.resilience4j.timelimiter.TimeLimiter.createdTimeoutExceptionWithName(TimeLimiter.java:225) ~[resilience4j-timelimiter-2.1.0.jar:2.1.0]
	at io.github.resilience4j.timelimiter.internal.TimeLimiterImpl$Timeout.lambda$of$0(TimeLimiterImpl.java:185) ~[resilience4j-timelimiter-2.1.0.jar:2.1.0]
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
	at java.base/java.lang.Thread.run(Thread.java:842) ~[na:na]

2024-03-10T21:56:08.264+05:30 ERROR 10626 --- [order-service] [o-auto-1-exec-9] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: java.util.concurrent.TimeoutException: TimeLimiter 'inventory' recorded a timeout exception.] with root cause

java.util.concurrent.TimeoutException: TimeLimiter 'inventory' recorded a timeout exception.
	at io.github.resilience4j.timelimiter.TimeLimiter.createdTimeoutExceptionWithName(TimeLimiter.java:225) ~[resilience4j-timelimiter-2.1.0.jar:2.1.0]
	at io.github.resilience4j.timelimiter.internal.TimeLimiterImpl$Timeout.lambda$of$0(TimeLimiterImpl.java:185) ~[resilience4j-timelimiter-2.1.0.jar:2.1.0]
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
	at java.base/java.lang.Thread.run(Thread.java:842) ~[na:na]

2024-03-10T21:56:15.457+05:30 DEBUG 10626 --- [order-service] [onPool-worker-2] org.hibernate.SQL                        : 
    insert 
    into
        "order"
        (order_number) 
    values
        (?)
Hibernate: 
    insert 
    into
        "order"
        (order_number) 
    values
        (?)
2024-03-10T21:56:15.470+05:30 DEBUG 10626 --- [order-service] [onPool-worker-2] org.hibernate.SQL                        : 
    insert 
    into
        item
        (price, quantity, sku_code) 
    values
        (?, ?, ?)
Hibernate: 
    insert 
    into
        item
        (price, quantity, sku_code) 
    values
        (?, ?, ?)
2024-03-10T21:56:15.472+05:30 DEBUG 10626 --- [order-service] [onPool-worker-2] org.hibernate.SQL                        : 
    insert 
    into
        item
        (price, quantity, sku_code) 
    values
        (?, ?, ?)
Hibernate: 
    insert 
    into
        item
        (price, quantity, sku_code) 
    values
        (?, ?, ?)
2024-03-10T21:56:15.482+05:30 DEBUG 10626 --- [order-service] [onPool-worker-2] org.hibernate.SQL                        : 
    update
        item 
    set
        order_id=? 
    where
        id=?
Hibernate: 
    update
        item 
    set
        order_id=? 
    where
        id=?
2024-03-10T21:56:15.483+05:30 DEBUG 10626 --- [order-service] [onPool-worker-2] org.hibernate.SQL                        : 
    update
        item 
    set
        order_id=? 
    where
        id=?
Hibernate: 
    update
        item 
    set
        order_id=? 
    where
        id=?
2024-03-10T21:56:15.486+05:30  INFO 10626 --- [order-service] [onPool-worker-2] o.e.orderservice.service.OrderService    : order created : Order(id=1, orderNumber=ORD-58f14bcb-31f6-4204-b34a-76bc1f493f2d, items=[Item(id=1, skuCode=SKU123123, price=19.99, quantity=2), Item(id=2, skuCode=SKU456x, price=29.99, quantity=1)])

Possible Solutions (if any):
[If you have any suggestions on what might be causing the issue or how to fix it, provide them here]

Your help in resolving this would be greatly appreciated!

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions