[BUG] cache not expire

[zhuzhihao94]

Describe the bug cache not expire ，chproxy version 1.17.2

To Reproduce 10s expire;but cache always hit; my config.yml: server: http: listen_addr: ":19090" #allowed_networks: ["0.0.0.0/0"] hack_me_please: true log_debug: true users:

• name: "default" password: "root123" to_cluster: "default" to_user: "default" max_concurrent_queries: 1000 max_execution_time: 10m #Enable response caching. See cache config below. cache: "default_cache"

clusters:

• name: "default"

  Requests are spread in round-robin + least-loaded fashion among nodes.

  Unreachable and unhealthy nodes are skipped.

  nodes: [ "192.168.100.74:8123", "192.168.192.116:8123", "192.168.192.117:8123", "192.168.192.118:8123" ] users:
  • name: "default" password: "root" caches:
  • name: "default_cache" mode: "file_system" file_system: dir: "/home/zhuzhihao/919/chproxy_bin/cache" max_size: 150Mb

  Cached responses will expire in 130s.

  expire: 10s

Expected behavior A clear and concise description of what you expected to happen.

[mga-chka]

were you using a previous version of chproxy that expired in 10sec? We will need to dig a bit but it doesn't look normal, the cache should expire after 10 sec.

[zhuzhihao94]

were you using a previous version of chproxy that expired in 10sec? We will need to dig a bit but it doesn't look normal, the cache should expire after 10 sec.

@mga-chka I haven't used any other version； cache expired only when clear cache dir and restart chproxy；

[mga-chka]

FYI @Blokje5 will soon take a look at this bug

[Blokje5]

@zhuzhihao94 I have not been able to reproduce your issue.

config.yml:

hack_me_please: true
log_debug: true

server:
  http:
    listen_addr: "0.0.0.0:9001"
users:
  - name: "default"
    password: "root123"
    to_cluster: "default"
    to_user: "user1"
    max_concurrent_queries: 1000
    max_execution_time: 10m
    cache: "default_cache"

clusters:
  - name: "default"
    nodes: ["clickhouse-server:8123"]
    users:
      - name: "user1"
        password: "pass1"

caches:
  - name: "default_cache"
    mode: "file_system"
    file_system:
      dir: "<path/to/local/filesystem>"
      max_size: 150Mb
    expire: 10s
    grace_time: 5s

Reproduction steps:

• Start a Clickhouse Cluster
• Create a User in Clickhouse (user1, pass1)
• Start CHProxy (1.1.7.2) ( docker run --link <clickhouse-container>:clickhouse-server -p 9001:9001 -v $(pwd):/config contentsquareplatform/chproxy:1.17.2 -config /config/test.yaml)

Results:

DEBUG: 2022/11/25 11:19:56 proxy.go:83: [ Id: 172ACFE3B8929EF9; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60880"; LocalAddr: "172.17.0.4:9001"; Duration: 3687 μs]: request start
DEBUG: 2022/11/25 11:19:56 proxy.go:392: [ Id: 172ACFE3B8929EF9; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60880"; LocalAddr: "172.17.0.4:9001"; Duration: 12215 μs]: cache miss
DEBUG: 2022/11/25 11:19:56 proxy.go:127: [ Id: 172ACFE3B8929EF9; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60880"; LocalAddr: "172.17.0.4:9001"; Duration: 14017 μs]: request success; query: "SELECT 1"; Method: GET; URL: "http://clickhouse-server:8123/?query=SELECT+1&query_id=172ACFE3B8929EF9&session_timeout=60"
DEBUG: 2022/11/25 11:20:01 proxy.go:83: [ Id: 172ACFE3B8929EFA; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60882"; LocalAddr: "172.17.0.4:9001"; Duration: 38 μs]: request start
DEBUG: 2022/11/25 11:20:01 proxy.go:283: [ Id: 172ACFE3B8929EFA; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60882"; LocalAddr: "172.17.0.4:9001"; Duration: 1403 μs]: cache hit
DEBUG: 2022/11/25 11:20:01 proxy.go:127: [ Id: 172ACFE3B8929EFA; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60882"; LocalAddr: "172.17.0.4:9001"; Duration: 1484 μs]: request success; query: "SELECT 1"; Method: GET; URL: "http://clickhouse-server:8123/?query=SELECT+1&query_id=172ACFE3B8929EFA&session_timeout=60"
DEBUG: 2022/11/25 11:20:32 proxy.go:83: [ Id: 172ACFE3B8929EFB; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60896"; LocalAddr: "172.17.0.4:9001"; Duration: 39 μs]: request start
DEBUG: 2022/11/25 11:20:32 proxy.go:392: [ Id: 172ACFE3B8929EFB; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60896"; LocalAddr: "172.17.0.4:9001"; Duration: 11184 μs]: cache miss
DEBUG: 2022/11/25 11:20:32 proxy.go:127: [ Id: 172ACFE3B8929EFB; User "default"(1) proxying as "user1"(1) to "clickhouse-server:8123"(1); RemoteAddr: "172.17.0.1:60896"; LocalAddr: "172.17.0.4:9001"; Duration: 11563 μs]: request success; query: "SELECT 1"; Method: GET; URL: "http://clickhouse-server:8123/?query=SELECT+1&query_id=172ACFE3B8929EFB&session_timeout=60"

In the logs you can see that there was a cache miss after waiting for the expire time (a few seconds in the config).

Would you be able to provide more context regarding the bug?

[mga-chka]

Hi @zhuzhihao94 , I'm closing this issue since we're laking information to reproduce it. Feel free to re-open it and give us more information