Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

bug: route 404 after upgrade to 3.2.2 #9951

Closed
wklken opened this issue Aug 2, 2023 · 26 comments · Fixed by #9967
Closed

bug: route 404 after upgrade to 3.2.2 #9951

wklken opened this issue Aug 2, 2023 · 26 comments · Fixed by #9967
Assignees
Labels
bug Something isn't working wait for update wait for the author's response in this issue/PR

Comments

@wklken
Copy link

wklken commented Aug 2, 2023

Current Behavior

register route and service into etcd, the changes not been watched and got 404

Expected Behavior

apisix watch the changes in time, the url should not be 404

Error Logs

I have create route/service 4 times, delete the instance and redo
only 1 time got an error log. another 3 times got no error log(still 404)

2023/08/02 08:28:44 [error] 1051#1051: *44434 upstream timed out (110: Connection timed out) while reading upstream, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", upstream: "http://10.1.1.1:2379/v3/watch", host: "127.0.0.1"

apisix reload

2023/08/02 08:49:43 [warn] 38#38: *19 [lua] config_etcd.lua:168: main etcd watcher started, revision=437733, context: ngx.timer
2023/08/02 08:49:43 [warn] 41#41: *36 [lua] config_etcd.lua:168: main etcd watcher started, revision=437733, context: ngx.timer

....
# do reload

2023/08/02 09:05:05 [notice] 770#770: signal process started
2023/08/02 09:05:05 [emerg] 773#773: bind() to 0.0.0.0:6008 failed (98: Address already in use)
2023/08/02 09:05:05 [warn] 771#771: *24136 [lua] config_etcd.lua:168: main etcd watcher started, revision=437755, context: ngx.timer

Steps to Reproduce

  1. upgrade apisix from 3.2.1 to 3.2.2
  2. register the service and route
  3. apisix-dashboard can see the route and service
  4. apisix admin api can fetch the route and service
  5. call the url, 404
  6. do apisix reload, call the url, 200;
  7. downgrade to apisix 3.2.1, do 2-5, call the url, 200;

got an error log

maybe this feature cause the error: #9456

Environment

  • APISIX version (run apisix version): 3.2.2
  • Operating system (run uname -a):
  • OpenResty / Nginx version (run openresty -V or nginx -V): nginx version: openresty/1.21.4.1
  • etcd version, if relevant (run curl http://127.0.0.1:9090/v1/server_info): 2.5.4
  • APISIX Dashboard version, if relevant:
  • Plugin runner version, for issues related to plugin runners:
  • LuaRocks version, for installation issues (run luarocks --version):
@wklken
Copy link
Author

wklken commented Aug 2, 2023

I change the log level to info, and after create the route/service, the changes have been watched and the config_etcd print the event; But still 404; I did not see any additional logs regarding what happened after the event was received.

2023/08/02 10:06:34 [info] 37#37: *19 [lua] config_etcd.lua:193: res_func: {
  result = {
    events = { {
        kv = {
          create_revision = "437830",
          key = "/bk-gateway-apisix/services/ddd.prod.stage-19",
          mod_revision = "437830",
          value = {
            create_time = 1690970794,
            desc = "正式环境",
            id = "ddd.prod.stage-19",
            labels = {
              ["gateway.bk.tencent.com/gateway"] = "ddd",
              ["gateway.bk.tencent.com/stage"] = "prod"
            },
            name = "ddd-prod-stage-prod-19",


2023/08/02 10:06:34 [info] 40#40: *36 [lua] config_etcd.lua:117: produce_res(): append res: {
  result = {
    events = { {
        kv = {
          create_revision = "437830",
          key = "/bk-gateway-apisix/services/ddd.prod.stage-19",
          mod_revision = "437830",
          value = {
            create_time = 1690970794,
            desc = "正式环境",
            id = "ddd.prod.stage-19",
            labels = {
              ["gateway.bk.tencent.com/gateway"] = "ddd",
              ["gateway.bk.tencent.com/stage"] = "prod"
            },
            name = "ddd-prod-stage-prod-19",

2023/08/02 10:06:34 [info] 37#37: *19 [lua] config_etcd.lua:193: res_func: {
  result = {
    events = { {
        kv = {
          create_revision = "437831",
          key = "/bk-gateway-apisix/routes/ddd.prod.-1",
          mod_revision = "437831",
          value = {
            create_time = 1690970794,
            desc = "获取发布信息,用于检查版本发布结果",
            id = "ddd.prod.-1",
            labels = {
              ["gateway.bk.tencent.com/gateway"] = "ddd",
              ["gateway.bk.tencent.com/stage"] = "prod"
            },
            methods = { "GET",
              <metatable> = <1>{}
            },
            name = "ddd-prod-apigw-builtin-mock-release-version",
            plugins = {


2023/08/02 10:06:34 [info] 40#40: *36 [lua] config_etcd.lua:117: produce_res(): append res: {
  result = {
    events = { {
        kv = {
          create_revision = "437831",
          key = "/bk-gateway-apisix/routes/ddd.prod.-1",
          mod_revision = "437831",
2023/08/02 10:07:22 [info] 40#40: *7873 [lua] v3.lua:187: _request_uri(): v3 request uri: /kv/range, timeout: 120, context: ngx.timer
2023/08/02 10:07:22 [info] 40#40: *7873 [lua] v3.lua:76: choose_endpoint(): choose endpoint: http://127.0.0.1:2379, context: ngx.timer
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] client.lua:123: dns_parse(): dns resolve bk-apigateway-etcd, result: {"class":1,"type":1,"section":1,"address":"2.2.2.2","ttl":30,"name":"bk-apigateway-etcd.default.svc.cluster.local"}, client: unix:, server: , request: "POST /v3/kv/range HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] resolver.lua:84: parse_domain(): parse addr: {"class":1,"type":1,"section":1,"address":"2.2.2.2","ttl":30,"name":"bk-apigateway-etcd.default.svc.cluster.local"}, client: unix:, server: , request: "POST /v3/kv/range HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] resolver.lua:85: parse_domain(): resolver: ["1.1.1.1"], client: unix:, server: , request: "POST /v3/kv/range HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] resolver.lua:86: parse_domain(): host: bk-apigateway-etcd, client: unix:, server: , request: "POST /v3/kv/range HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] resolver.lua:88: parse_domain(): dns resolver domain: bk-apigateway-etcd to 2.2.2.2, client: unix:, server: , request: "POST /v3/kv/range HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 40#40: *7873 [lua] v3.lua:187: keepalive(): v3 request uri: /lease/keepalive, timeout: nil, context: ngx.timer
2023/08/02 10:07:22 [info] 40#40: *7873 [lua] v3.lua:76: choose_endpoint(): choose endpoint: http://127.0.0.1:2379, context: ngx.timer
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] client.lua:123: dns_parse(): dns resolve bk-apigateway-etcd, result: {"class":1,"type":1,"section":1,"address":"2.2.2.2","ttl":30,"name":"bk-apigateway-etcd.default.svc.cluster.local"}, client: unix:, server: , request: "POST /v3/lease/keepalive HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] resolver.lua:84: parse_domain(): parse addr: {"class":1,"type":1,"section":1,"address":"2.2.2.2","ttl":30,"name":"bk-apigateway-etcd.default.svc.cluster.local"}, client: unix:, server: , request: "POST /v3/lease/keepalive HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] resolver.lua:85: parse_domain(): resolver: ["1.1.1.1"], client: unix:, server: , request: "POST /v3/lease/keepalive HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] resolver.lua:86: parse_domain(): host: bk-apigateway-etcd, client: unix:, server: , request: "POST /v3/lease/keepalive HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:22 [info] 37#37: *6184 [lua] resolver.lua:88: parse_domain(): dns resolver domain: bk-apigateway-etcd to 2.2.2.2, client: unix:, server: , request: "POST /v3/lease/keepalive HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:07:24 [info] 40#40: *36 [lua] config_etcd.lua:193: res_func: nil, context: ngx.timer
2023/08/02 10:07:24 [info] 40#40: *36 [lua] config_etcd.lua:107: cancel_watch(): cancel watch connection success, context: ngx.timer
2023/08/02 10:07:24 [info] 40#40: *36 [lua] config_etcd.lua:181: restart watchdir: start_revision=437835, context: ngx.timer
2023/08/02 10:07:24 [info] 37#37: *5479 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while reading upstream, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", upstream: "http://2.2.2.2:2379/v3/watch", host: "127.0.0.1"
2023/08/02 10:07:24 [info] 40#40: *36 [lua] v3.lua:76: choose_endpoint(): choose endpoint: http://127.0.0.1:2379, context: ngx.timer
2023/08/02 10:07:24 [info] 37#37: *19 [lua] config_etcd.lua:193: res_func: nil, context: ngx.timer
2023/08/02 10:07:24 [info] 37#37: *19 [lua] config_etcd.lua:107: cancel_watch(): cancel watch connection success, context: ngx.timer
2023/08/02 10:07:24 [info] 37#37: *19 [lua] config_etcd.lua:181: restart watchdir: start_revision=437835, context: ngx.timer
2023/08/02 10:07:24 [info] 37#37: *19 [lua] v3.lua:76: choose_endpoint(): choose endpoint: http://127.0.0.1:2379, context: ngx.timer
2023/08/02 10:08:14 [info] 37#37: *7948 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while reading upstream, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", upstream: "http://2.2.2.2:2379/v3/watch", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 40#40: *36 [lua] config_etcd.lua:193: res_func: nil, context: ngx.timer
2023/08/02 10:08:14 [info] 37#37: *9249 [lua] client.lua:123: dns_parse(): dns resolve bk-apigateway-etcd, result: {"class":1,"type":1,"section":1,"address":"2.2.2.2","ttl":30,"name":"bk-apigateway-etcd.default.svc.cluster.local"}, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 37#37: *9249 [lua] resolver.lua:84: parse_domain(): parse addr: {"class":1,"type":1,"section":1,"address":"2.2.2.2","ttl":30,"name":"bk-apigateway-etcd.default.svc.cluster.local"}, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 40#40: *36 [lua] config_etcd.lua:107: cancel_watch(): cancel watch connection success, context: ngx.timer
2023/08/02 10:08:14 [info] 37#37: *9249 [lua] resolver.lua:85: parse_domain(): resolver: ["1.1.1.1"], client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 40#40: *36 [lua] config_etcd.lua:181: restart watchdir: start_revision=437835, context: ngx.timer
2023/08/02 10:08:14 [info] 37#37: *9249 [lua] resolver.lua:86: parse_domain(): host: bk-apigateway-etcd, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 37#37: *9249 [lua] resolver.lua:88: parse_domain(): dns resolver domain: bk-apigateway-etcd to 2.2.2.2, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 40#40: *36 [lua] v3.lua:76: choose_endpoint(): choose endpoint: http://127.0.0.1:2379, context: ngx.timer
2023/08/02 10:08:14 [info] 37#37: *6184 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while reading upstream, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", upstream: "http://2.2.2.2:2379/v3/watch", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 37#37: *8582 [lua] client.lua:123: dns_parse(): dns resolve bk-apigateway-etcd, result: {"class":1,"type":1,"section":1,"address":"2.2.2.2","ttl":30,"name":"bk-apigateway-etcd.default.svc.cluster.local"}, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 37#37: *8582 [lua] resolver.lua:84: parse_domain(): parse addr: {"class":1,"type":1,"section":1,"address":"2.2.2.2","ttl":30,"name":"bk-apigateway-etcd.default.svc.cluster.local"}, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 37#37: *8582 [lua] resolver.lua:85: parse_domain(): resolver: ["1.1.1.1"], client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 37#37: *8582 [lua] resolver.lua:86: parse_domain(): host: bk-apigateway-etcd, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/02 10:08:14 [info] 37#37: *8582 [lua] resolver.lua:88: parse_domain(): dns resolver domain: bk-apigateway-etcd to 2.2.2.2, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"

@qihaiyan
Copy link
Contributor

qihaiyan commented Aug 2, 2023

Same error occurs to me.

@jiangfucheng
Copy link
Member

@wklken Hi, I can't reproduce this issue, here is my reproduction step, please help me check the difference with your description.

  1. checkout code to 3.2.2
    git checkout -b 3.2.2 3.2.2
  2. update dependency
    make deps
  3. start apisix
    make run
  4. create route (I start a nginx as backend server with 9081 port)
 curl 127.0.0.1:9180/apisix/admin/routes/1 -H "X-API-KEY: edd1c9f034335f136f87ad84b625c8f1" -X PUT -d '
{
  "uri": "/*",
  "name": "test",
  "methods": [
    "GET",
    "POST",
    "PUT",
    "DELETE",
    "PATCH",
    "HEAD",
    "OPTIONS",
    "CONNECT",
    "TRACE",
    "PURGE"
  ],
  "upstream": {
    "nodes": [
      {
        "host": "127.0.0.1",
        "port": 9081,
        "weight": 1
      }
    ],
    "timeout": {
      "connect": 6,
      "send": 6,
      "read": 6
    },
    "type": "roundrobin",
    "scheme": "http",
    "pass_host": "pass",
    "keepalive_pool": {
      "idle_timeout": 60,
      "requests": 1000,
      "size": 320
    }
  },
  "status": 1
}'
  1. access apisix
    curl localhost:9080
  2. check the result
    hello web1%

@qihaiyan
Copy link
Contributor

qihaiyan commented Aug 2, 2023

try using a etcd cluster with auth enabled @jiangfucheng

@jiangfucheng
Copy link
Member

try using a etcd cluster with auth enabled @jiangfucheng

I follow this project https://github.com/guessi/docker-compose-etcd to start an etcd cluster in my local env, and enable auth, but still can't reproduce this issue.

@wklken
Copy link
Author

wklken commented Aug 3, 2023

I run the apisix in k8s, the etcd address is a service(bitnami etcd helm chart)
And I set timeout to 120

deployment:
  role: traditional
  role_traditional:
    config_provider: etcd
  etcd:
    host:
      - "http://apigateway-etcd:2379"
    timeout: 120
    prefix: /gateway-apisix
    user: root
    password: xxxx

and, maybe you should change the route into route+service

@qihaiyan
Copy link
Contributor

qihaiyan commented Aug 3, 2023

I use route+service too, maybe this is the cause.

@wklken
Copy link
Author

wklken commented Aug 3, 2023

after register the route+service, got 404

curl 'http://127.0.0.1:9180/apisix/admin/services/eee.prod.stage-20' -H 'X-API-KEY: eex3P86cLLSlAOagO1em3FADrRXhMR2c' | jq

{
  "key": "/bk-gateway-apisix/services/eee.prod.stage-20",
  "modifiedIndex": 437855,
  "value": {
    "labels": {
      "gateway.bk.tencent.com/stage": "prod",
      "gateway.bk.tencent.com/gateway": "eee"
    },
    "update_time": 1691028294,

the modifiedIndex is 437855

and the log, /watch start_revisions is 437868, so at that time, the apisix has no newest config data, and it will never know the changes until reload/restart

2023/08/03 02:10:04 [info] 37#37: *19 [lua] v3.lua:852: request_chunk(): http request method: POST path: /watch body: {"create_request":{"range_end":"L2JrLWdhdGV3YXktYXBpc2l4MA==","key":"L2JrLWdhdGV3YXktYXBpc2l4Lw==","start_revision":437868}} query: nil, context: ngx.timer
2023/08/03 02:10:04 [info] 37#37: *19 [lua] config_etcd.lua:193: res_func: {
  result = {
    created = true,
    header = {
      cluster_id = "3892788201713343575",
      member_id = "12985827509394625062",
      raft_term = "57",
      revision = "437868"
    }
  }
}, context: ngx.timer

and I add another route+service, 404;

2023/08/03 02:22:05 [info] 40#40: *40 [lua] config_etcd.lua:193: res_func: nil, context: ngx.timer
2023/08/03 02:22:05 [info] 40#40: *40 [lua] config_etcd.lua:107: cancel_watch(): cancel watch connection success, context: ngx.timer
2023/08/03 02:22:05 [info] 40#40: *40 [lua] config_etcd.lua:181: restart watchdir: start_revision=437886, context: ngx.timer
2023/08/03 02:22:05 [info] 37#37: *28877 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while reading upstream, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", upstream: "http://1.1.1.1:2379/v3/watch", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 40#40: *40 [lua] v3.lua:76: choose_endpoint(): choose endpoint: http://127.0.0.1:2379, context: ngx.timer
2023/08/03 02:22:05 [info] 37#37: *19 [lua] config_etcd.lua:193: res_func: nil, context: ngx.timer
2023/08/03 02:22:05 [info] 37#37: *19 [lua] config_etcd.lua:107: cancel_watch(): cancel watch connection success, context: ngx.timer
2023/08/03 02:22:05 [info] 37#37: *19 [lua] config_etcd.lua:181: restart watchdir: start_revision=437886, context: ngx.timer
2023/08/03 02:22:05 [info] 37#37: *19 [lua] v3.lua:76: choose_endpoint(): choose endpoint: http://127.0.0.1:2379, context: ngx.timer
2023/08/03 02:22:05 [info] 37#37: *29656 [lua] client.lua:123: dns_parse(): dns resolve bk-apigateway-etcd, result: {"class":1,"address":"1.1.1.1","section":1,"name":"bk-apigateway-etcd.default.svc.cluster.local","ttl":30,"type":1}, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *29656 [lua] resolver.lua:84: parse_domain(): parse addr: {"class":1,"section":1,"address":"1.1.1.1","name":"bk-apigateway-etcd.default.svc.cluster.local","ttl":30,"type":1}, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *29656 [lua] resolver.lua:85: parse_domain(): resolver: ["10.96.0.10"], client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *29656 [lua] resolver.lua:86: parse_domain(): host: bk-apigateway-etcd, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *29656 [lua] resolver.lua:88: parse_domain(): dns resolver domain: bk-apigateway-etcd to 1.1.1.1, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *29589 epoll_wait() reported that client prematurely closed connection, so upstream connection is closed too while reading upstream, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", upstream: "http://1.1.1.1:2379/v3/watch", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *30892 [lua] client.lua:123: dns_parse(): dns resolve bk-apigateway-etcd, result: {"class":1,"address":"1.1.1.1","section":1,"name":"bk-apigateway-etcd.default.svc.cluster.local","ttl":30,"type":1}, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *30892 [lua] resolver.lua:84: parse_domain(): parse addr: {"class":1,"section":1,"address":"1.1.1.1","name":"bk-apigateway-etcd.default.svc.cluster.local","ttl":30,"type":1}, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *30892 [lua] resolver.lua:85: parse_domain(): resolver: ["10.96.0.10"], client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *30892 [lua] resolver.lua:86: parse_domain(): host: bk-apigateway-etcd, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 37#37: *30892 [lua] resolver.lua:88: parse_domain(): dns resolver domain: bk-apigateway-etcd to 1.1.1.1, client: unix:, server: , request: "POST /v3/watch HTTP/1.1", host: "127.0.0.1"
2023/08/03 02:22:05 [info] 40#40: *40 [lua] v3.lua:852: request_chunk(): http request method: POST path: /watch body: {"create_request":{"range_end":"L2JrLWdhdGV3YXktYXBpc2l4MA==","key":"L2JrLWdhdGV3YXktYXBpc2l4Lw==","start_revision":437886}} query: nil, context: ngx.timer
2023/08/03 02:22:05 [info] 37#37: *19 [lua] v3.lua:852: request_chunk(): http request method: POST path: /watch body: {"create_request":{"range_end":"L2JrLWdhdGV3YXktYXBpc2l4MA==","key":"L2JrLWdhdGV3YXktYXBpc2l4Lw==","start_revision":437886}} query: nil, context: ngx.timer
2023/08/03 02:22:05 [info] 40#40: *40 [lua] config_etcd.lua:193: res_func: {
  result = {
    created = true,
    header = {
      cluster_id = "3892788201713343575",
      member_id = "12985827509394625062",
      raft_term = "57",
      revision = "437886"
    }
  }
}, context: ngx.timer

there are no logs between 437868 to 437886

How the apisix know the start_reversion after it canceled and start a new connection?

@wklken
Copy link
Author

wklken commented Aug 3, 2023

@jiangfucheng can you please raise the level of this bug? Version 3.2.2/3.4.0/3.4.1 may all be affected(if it's related to #9456), especially if deploy or upgrade in a production environment.

@jiangfucheng
Copy link
Member

@monkeyDluffy6017 @kingluo Hi, could you help take a look at this issue, I don't have enough time to process this issue in a timely manner.

@monkeyDluffy6017
Copy link
Contributor

@Sn0rt Could you help to check?

@Sn0rt
Copy link
Contributor

Sn0rt commented Aug 3, 2023

got. I will try to reproduce this .

@wklken @qihaiyan can you help me check the reproduce step ?

I can't reproduce your case follow the step as below.

check out 3.2.1

check out the 3.2.1 tag and install deps

~/w/apisix> git co 3.2.1
HEAD is now at f81a386d feat: release apisix 3.2.1 (#9559)
~/w/apisix> make deps
Wrote
	variables.OPENSSL_LIBDIR = "/opt/homebrew/opt/openresty-openssl111/lib"
to
	/Users/guohao/.luarocks/config-5.1.lua
Wrote
	variables.OPENSSL_INCDIR = "/opt/homebrew/opt/openresty-openssl111/include"
to
	/Users/guohao/.luarocks/config-5.1.lua

apisix master-0 depends on lua-resty-ctxdump 0.1-0 (0.1-0 installed)
apisix master-0 depends on api7-lua-resty-dns-client 7.0.1 (7.0.1-0 installed)
apisix master-0 depends on lua-resty-template 2.0 (2.0-1 installed)
apisix master-0 depends on lua-resty-etcd 1.10.4 (1.10.4-0 installed)
apisix master-0 depends on api7-lua-resty-http 0.2.0 (0.2.0-0 installed)
apisix master-0 depends on lua-resty-balancer 0.04 (0.04-0 installed)
apisix master-0 depends on lua-resty-ngxvar 0.5.2 (0.5.2-0 installed)
apisix master-0 depends on lua-resty-jit-uuid 0.0.7 (0.0.7-2 installed)
apisix master-0 depends on lua-resty-healthcheck-api7 2.2.2 (2.2.2-0 installed)
apisix master-0 depends on api7-lua-resty-jwt 0.2.4 (0.2.4-0 installed)
apisix master-0 depends on lua-resty-hmac-ffi 0.05 (0.05-0 installed)
apisix master-0 depends on lua-resty-cookie 0.1.0 (0.1.0-2 installed)
apisix master-0 depends on lua-resty-session 3.10 (3.10-1 installed)
apisix master-0 depends on opentracing-openresty 0.1 (0.1-0 installed)
apisix master-0 depends on lua-resty-radixtree 2.8.2 (2.8.2-0 installed)
apisix master-0 depends on lua-protobuf 0.4.1 (0.4.1-1 installed)
apisix master-0 depends on lua-resty-openidc 1.7.5 (1.7.5-1 installed)
apisix master-0 depends on luafilesystem 1.7.0-2 (1.7.0-2 installed)
apisix master-0 depends on api7-lua-tinyyaml 0.4.2 (0.4.2-0 installed)
apisix master-0 depends on nginx-lua-prometheus 0.20220527 (0.20220527-1 installed)
apisix master-0 depends on jsonschema 0.9.8 (0.9.8-0 installed)
apisix master-0 depends on lua-resty-ipmatcher 0.6.1 (0.6.1-0 installed)
apisix master-0 depends on lua-resty-kafka 0.20-0 (0.20-0 installed)
apisix master-0 depends on lua-resty-logger-socket 2.0.1-0 (2.0.1-0 installed)
apisix master-0 depends on skywalking-nginx-lua 0.6.0 (0.6.0-0 installed)
apisix master-0 depends on base64 1.5-2 (1.5-2 installed)
apisix master-0 depends on binaryheap 0.4 (0.4-1 installed)
apisix master-0 depends on api7-dkjson 0.1.1 (0.1.1-0 installed)
apisix master-0 depends on resty-redis-cluster 1.02-4 (1.02-4 installed)
apisix master-0 depends on lua-resty-expr 1.3.2 (1.3.2-0 installed)
apisix master-0 depends on graphql 0.0.2 (0.0.2-1 installed)
apisix master-0 depends on argparse 0.7.1-1 (0.7.1-1 installed)
apisix master-0 depends on luasocket 3.1.0-1 (3.1.0-1 installed)
apisix master-0 depends on luasec 0.9-1 (0.9-1 installed)
apisix master-0 depends on lua-resty-consul 0.3-2 (0.3-2 installed)
apisix master-0 depends on penlight 1.9.2-1 (1.9.2-1 installed)
apisix master-0 depends on ext-plugin-proto 0.6.0 (0.6.0-0 installed)
apisix master-0 depends on casbin 1.41.5 (1.41.5-1 installed)
apisix master-0 depends on api7-snowflake 2.0-1 (2.0-1 installed)
apisix master-0 depends on inspect 3.1.1 (3.1.1-0 installed)
apisix master-0 depends on lualdap 1.2.6-1 (1.2.6-1 installed)
apisix master-0 depends on lua-resty-rocketmq 0.3.0-0 (0.3.0-0 installed)
apisix master-0 depends on opentelemetry-lua 0.2-3 (0.2-3 installed)
apisix master-0 depends on net-url 0.9-1 (0.9-1 installed)
apisix master-0 depends on xml2lua 1.5-2 (1.5-2 installed)
apisix master-0 depends on nanoid 0.1-1 (0.1-1 installed)
apisix master-0 depends on lua-resty-mediador 0.1.2-1 (0.1.2-1 installed)
apisix master-0 depends on lua-resty-ldap 0.1.0-0 (0.1.0-0 installed)
Stopping after installing dependencies for apisix master-0

register service and router

test the router for confirm the router is empty.

~/w/apisix> curl http://localhost:9080/anything -v
* processing: http://localhost:9080/anything
*   Trying [::1]:9080...
* Connected to localhost (::1) port 9080
> GET /anything HTTP/1.1
> Host: localhost:9080
> User-Agent: curl/8.2.1
> Accept: */*
>
< HTTP/1.1 404 Not Found
< Date: Thu, 03 Aug 2023 07:40:02 GMT
< Content-Type: text/plain; charset=utf-8
< Transfer-Encoding: chunked
< Connection: keep-alive
< Server: APISIX/3.2.1
<
{"error_msg":"404 Route Not Found"}
* Connection #0 to host localhost left intact

create the service and router

~/w/apisix> curl http://127.0.0.1:9180/apisix/admin/services/200 \
                                                -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d '
                                    {
                                        "upstream": {
                                            "type": "roundrobin",
                                            "nodes": {
                                          "httpbin.org:80": 1
                                            }
                                        }
                                    }'
{"key":"/apisix/services/200","value":{"id":"200","upstream":{"type":"roundrobin","nodes":{"httpbin.org:80":1},"hash_on":"vars","pass_host":"pass","scheme":"http"},"create_time":1691048414,"update_time":1691048414}}

now create the router

~/w/apisix> curl http://127.0.0.1:9180/apisix/admin/routes/100 \
                                -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d '
                        {
                            "methods": ["GET"],
                            "uri": "/anything",
                            "service_id": "200"
                        }'
{"key":"/apisix/routes/100","value":{"priority":0,"service_id":"200","methods":["GET"],"id":"100","uri":"/anything","status":1,"create_time":1691048440,"update_time":1691048440}}

test the router

~/w/apisix> curl http://localhost:9080/anything -v
* processing: http://localhost:9080/anything
*   Trying [::1]:9080...
* Connected to localhost (::1) port 9080
> GET /anything HTTP/1.1
> Host: localhost:9080
> User-Agent: curl/8.2.1
> Accept: */*
>
< HTTP/1.1 200 OK
< Content-Type: application/json
< Content-Length: 382
< Connection: keep-alive
< Date: Thu, 03 Aug 2023 07:40:47 GMT
< Access-Control-Allow-Origin: *
< Access-Control-Allow-Credentials: true
< Server: APISIX/3.2.1
<
{
  "args": {},
  "data": "",
  "files": {},
  "form": {},
  "headers": {
    "Accept": "*/*",
    "Host": "localhost",
    "User-Agent": "curl/8.2.1",
    "X-Amzn-Trace-Id": "Root=1-64cb59fb-1f3fe0963bb8d3a73c33e05c",
    "X-Forwarded-Host": "localhost"
  },
  "json": null,
  "method": "GET",
  "origin": "::1, 220.246.124.214",
  "url": "http://localhost/anything"
}
* Connection #0 to host localhost left intact

switch to 3.2.2

now checkout the tag 3.2.2

~/w/apisix> git co 3.2.2
Previous HEAD position was f81a386d feat: release apisix 3.2.1 (#9559)
HEAD is now at 77704832 feat: release APISIX 3.2.2 (#9723)
~/w/apisix> make deps
Wrote
	variables.OPENSSL_LIBDIR = "/opt/homebrew/opt/openresty-openssl111/lib"
to
	/Users/guohao/.luarocks/config-5.1.lua
Wrote
	variables.OPENSSL_INCDIR = "/opt/homebrew/opt/openresty-openssl111/include"
to
	/Users/guohao/.luarocks/config-5.1.lua
Missing dependencies for apisix master-0:
   api7-lua-resty-jwt 0.2.5 (not installed)

apisix master-0 depends on lua-resty-ctxdump 0.1-0 (0.1-0 installed)
apisix master-0 depends on api7-lua-resty-dns-client 7.0.1 (7.0.1-0 installed)
apisix master-0 depends on lua-resty-template 2.0 (2.0-1 installed)
apisix master-0 depends on lua-resty-etcd 1.10.4 (1.10.4-0 installed)
apisix master-0 depends on api7-lua-resty-http 0.2.0 (0.2.0-0 installed)
apisix master-0 depends on lua-resty-balancer 0.04 (0.04-0 installed)
apisix master-0 depends on lua-resty-ngxvar 0.5.2 (0.5.2-0 installed)
apisix master-0 depends on lua-resty-jit-uuid 0.0.7 (0.0.7-2 installed)
apisix master-0 depends on lua-resty-healthcheck-api7 2.2.2 (2.2.2-0 installed)
apisix master-0 depends on api7-lua-resty-jwt 0.2.5 (not installed)
Installing https://luarocks.org/api7-lua-resty-jwt-0.2.5-0.src.rock

api7-lua-resty-jwt 0.2.5-0 depends on lua >= 5.1 (5.1-1 provided by VM)
api7-lua-resty-jwt 0.2.5-0 depends on lua-resty-openssl >= 0.6.8 (0.8.22-1 installed)
api7-lua-resty-jwt 0.2.5-0 is now installed in /Users/guohao/workspace/apisix/deps (license: Apache License Version 2)

Checking stability of dependencies in the absence of
api7-lua-resty-jwt 0.2.4-0...

Removing api7-lua-resty-jwt 0.2.4-0...
Removal successful.
apisix master-0 depends on lua-resty-hmac-ffi 0.05 (0.05-0 installed)
apisix master-0 depends on lua-resty-cookie 0.1.0 (0.1.0-2 installed)
apisix master-0 depends on lua-resty-session 3.10 (3.10-1 installed)
apisix master-0 depends on opentracing-openresty 0.1 (0.1-0 installed)
apisix master-0 depends on lua-resty-radixtree 2.8.2 (2.8.2-0 installed)
apisix master-0 depends on lua-protobuf 0.4.1 (0.4.1-1 installed)
apisix master-0 depends on lua-resty-openidc 1.7.5 (1.7.5-1 installed)
apisix master-0 depends on luafilesystem 1.7.0-2 (1.7.0-2 installed)
apisix master-0 depends on api7-lua-tinyyaml 0.4.2 (0.4.2-0 installed)
apisix master-0 depends on nginx-lua-prometheus 0.20220527 (0.20220527-1 installed)
apisix master-0 depends on jsonschema 0.9.8 (0.9.8-0 installed)
apisix master-0 depends on lua-resty-ipmatcher 0.6.1 (0.6.1-0 installed)
apisix master-0 depends on lua-resty-kafka 0.20-0 (0.20-0 installed)
apisix master-0 depends on lua-resty-logger-socket 2.0.1-0 (2.0.1-0 installed)
apisix master-0 depends on skywalking-nginx-lua 0.6.0 (0.6.0-0 installed)
apisix master-0 depends on base64 1.5-2 (1.5-2 installed)
apisix master-0 depends on binaryheap 0.4 (0.4-1 installed)
apisix master-0 depends on api7-dkjson 0.1.1 (0.1.1-0 installed)
apisix master-0 depends on resty-redis-cluster 1.02-4 (1.02-4 installed)
apisix master-0 depends on lua-resty-expr 1.3.2 (1.3.2-0 installed)
apisix master-0 depends on graphql 0.0.2 (0.0.2-1 installed)
apisix master-0 depends on argparse 0.7.1-1 (0.7.1-1 installed)
apisix master-0 depends on luasocket 3.1.0-1 (3.1.0-1 installed)
apisix master-0 depends on luasec 0.9-1 (0.9-1 installed)
apisix master-0 depends on lua-resty-consul 0.3-2 (0.3-2 installed)
apisix master-0 depends on penlight 1.9.2-1 (1.9.2-1 installed)
apisix master-0 depends on ext-plugin-proto 0.6.0 (0.6.0-0 installed)
apisix master-0 depends on casbin 1.41.5 (1.41.5-1 installed)
apisix master-0 depends on api7-snowflake 2.0-1 (2.0-1 installed)
apisix master-0 depends on inspect 3.1.1 (3.1.1-0 installed)
apisix master-0 depends on lualdap 1.2.6-1 (1.2.6-1 installed)
apisix master-0 depends on lua-resty-rocketmq 0.3.0-0 (0.3.0-0 installed)
apisix master-0 depends on opentelemetry-lua 0.2-3 (0.2-3 installed)
apisix master-0 depends on net-url 0.9-1 (0.9-1 installed)
apisix master-0 depends on xml2lua 1.5-2 (1.5-2 installed)
apisix master-0 depends on nanoid 0.1-1 (0.1-1 installed)
apisix master-0 depends on lua-resty-mediador 0.1.2-1 (0.1.2-1 installed)
apisix master-0 depends on lua-resty-ldap 0.1.0-0 (0.1.0-0 installed)
Stopping after installing dependencies for apisix master-0

re-load the APISIX

~/w/apisix> make reload
[ info ] reload -> [ Start ]
/Users/guohao/workspace/apisix/bin/apisix reload
/usr/local/openresty//luajit/bin/luajit ./apisix/cli/apisix.lua reload
[ info ] reload -> [ Done ]

test the router

~/w/apisix> curl http://localhost:9080/anything -v
* processing: http://localhost:9080/anything
*   Trying [::1]:9080...
* Connected to localhost (::1) port 9080
> GET /anything HTTP/1.1
> Host: localhost:9080
> User-Agent: curl/8.2.1
> Accept: */*
>
< HTTP/1.1 200 OK
< Content-Type: application/json
< Content-Length: 382
< Connection: keep-alive
< Date: Thu, 03 Aug 2023 07:41:12 GMT
< Access-Control-Allow-Origin: *
< Access-Control-Allow-Credentials: true
< Server: APISIX/3.2.2
<
{
  "args": {},
  "data": "",
  "files": {},
  "form": {},
  "headers": {
    "Accept": "*/*",
    "Host": "localhost",
    "User-Agent": "curl/8.2.1",
    "X-Amzn-Trace-Id": "Root=1-64cb5a14-4f21c4e612b9f52b646cf3d5",
    "X-Forwarded-Host": "localhost"
  },
  "json": null,
  "method": "GET",
  "origin": "::1, 220.246.124.214",
  "url": "http://localhost/anything"
}
* Connection #0 to host localhost left intact

@AlinsRan AlinsRan added bug Something isn't working wait for update wait for the author's response in this issue/PR labels Aug 3, 2023
@wklken
Copy link
Author

wklken commented Aug 3, 2023

@Sn0rt create the route and service on the version 3.2.2

  • the first sync after start is right
  • the sync after reload is right too
  • only the changes after start would be 404

@Sn0rt
Copy link
Contributor

Sn0rt commented Aug 3, 2023

upgrade apisix from 3.2.1 to 3.2.2

ok. I will update the reproduce step.

ok. the bug has been reproduced.

check out 3.2.2

check the code from tag 3.2.2

~/w/apisix> git co 3.2.2
HEAD is now at 77704832 feat: release APISIX 3.2.2 (#9723)
~/w/apisix> make deps
Wrote
	variables.OPENSSL_LIBDIR = "/opt/homebrew/opt/openresty-openssl111/lib"
to
	/Users/guohao/.luarocks/config-5.1.lua
Wrote
	variables.OPENSSL_INCDIR = "/opt/homebrew/opt/openresty-openssl111/include"
to
	/Users/guohao/.luarocks/config-5.1.lua

apisix master-0 depends on lua-resty-ctxdump 0.1-0 (0.1-0 installed)
apisix master-0 depends on api7-lua-resty-dns-client 7.0.1 (7.0.1-0 installed)
apisix master-0 depends on lua-resty-template 2.0 (2.0-1 installed)
apisix master-0 depends on lua-resty-etcd 1.10.4 (1.10.4-0 installed)
apisix master-0 depends on api7-lua-resty-http 0.2.0 (0.2.0-0 installed)
apisix master-0 depends on lua-resty-balancer 0.04 (0.04-0 installed)
apisix master-0 depends on lua-resty-ngxvar 0.5.2 (0.5.2-0 installed)
apisix master-0 depends on lua-resty-jit-uuid 0.0.7 (0.0.7-2 installed)
apisix master-0 depends on lua-resty-healthcheck-api7 2.2.2 (2.2.2-0 installed)
apisix master-0 depends on api7-lua-resty-jwt 0.2.5 (0.2.5-0 installed)
apisix master-0 depends on lua-resty-hmac-ffi 0.05 (0.05-0 installed)
apisix master-0 depends on lua-resty-cookie 0.1.0 (0.1.0-2 installed)
apisix master-0 depends on lua-resty-session 3.10 (3.10-1 installed)
apisix master-0 depends on opentracing-openresty 0.1 (0.1-0 installed)
apisix master-0 depends on lua-resty-radixtree 2.8.2 (2.8.2-0 installed)
apisix master-0 depends on lua-protobuf 0.4.1 (0.4.1-1 installed)
apisix master-0 depends on lua-resty-openidc 1.7.5 (1.7.5-1 installed)
apisix master-0 depends on luafilesystem 1.7.0-2 (1.7.0-2 installed)
apisix master-0 depends on api7-lua-tinyyaml 0.4.2 (0.4.2-0 installed)
apisix master-0 depends on nginx-lua-prometheus 0.20220527 (0.20220527-1 installed)
apisix master-0 depends on jsonschema 0.9.8 (0.9.8-0 installed)
apisix master-0 depends on lua-resty-ipmatcher 0.6.1 (0.6.1-0 installed)
apisix master-0 depends on lua-resty-kafka 0.20-0 (0.20-0 installed)
apisix master-0 depends on lua-resty-logger-socket 2.0.1-0 (2.0.1-0 installed)
apisix master-0 depends on skywalking-nginx-lua 0.6.0 (0.6.0-0 installed)
apisix master-0 depends on base64 1.5-2 (1.5-2 installed)
apisix master-0 depends on binaryheap 0.4 (0.4-1 installed)
apisix master-0 depends on api7-dkjson 0.1.1 (0.1.1-0 installed)
apisix master-0 depends on resty-redis-cluster 1.02-4 (1.02-4 installed)
apisix master-0 depends on lua-resty-expr 1.3.2 (1.3.2-0 installed)
apisix master-0 depends on graphql 0.0.2 (0.0.2-1 installed)
apisix master-0 depends on argparse 0.7.1-1 (0.7.1-1 installed)
apisix master-0 depends on luasocket 3.1.0-1 (3.1.0-1 installed)
apisix master-0 depends on luasec 0.9-1 (0.9-1 installed)
apisix master-0 depends on lua-resty-consul 0.3-2 (0.3-2 installed)
apisix master-0 depends on penlight 1.9.2-1 (1.9.2-1 installed)
apisix master-0 depends on ext-plugin-proto 0.6.0 (0.6.0-0 installed)
apisix master-0 depends on casbin 1.41.5 (1.41.5-1 installed)
apisix master-0 depends on api7-snowflake 2.0-1 (2.0-1 installed)
apisix master-0 depends on inspect 3.1.1 (3.1.1-0 installed)
apisix master-0 depends on lualdap 1.2.6-1 (1.2.6-1 installed)
apisix master-0 depends on lua-resty-rocketmq 0.3.0-0 (0.3.0-0 installed)
apisix master-0 depends on opentelemetry-lua 0.2-3 (0.2-3 installed)
apisix master-0 depends on net-url 0.9-1 (0.9-1 installed)
apisix master-0 depends on xml2lua 1.5-2 (1.5-2 installed)
apisix master-0 depends on nanoid 0.1-1 (0.1-1 installed)
apisix master-0 depends on lua-resty-mediador 0.1.2-1 (0.1.2-1 installed)
apisix master-0 depends on lua-resty-ldap 0.1.0-0 (0.1.0-0 installed)
Stopping after installing dependencies for apisix master-0

~/w/apisix> make reload
[ info ] reload -> [ Start ]
/Users/guohao/workspace/apisix/bin/apisix reload
/usr/local/openresty//luajit/bin/luajit ./apisix/cli/apisix.lua reload
[ info ] reload -> [ Done ]

test the router not be installed

~/w/apisix> curl http://localhost:9080/anything -v
* processing: http://localhost:9080/anything
*   Trying [::1]:9080...
* Connected to localhost (::1) port 9080
> GET /anything HTTP/1.1
> Host: localhost:9080
> User-Agent: curl/8.2.1
> Accept: */*
>
< HTTP/1.1 404 Not Found
< Date: Thu, 03 Aug 2023 08:13:49 GMT
< Content-Type: text/plain; charset=utf-8
< Transfer-Encoding: chunked
< Connection: keep-alive
< Server: APISIX/3.2.2
<
{"error_msg":"404 Route Not Found"}
* Connection #0 to host localhost left intact

create service and router

create a service and router

~/w/apisix> curl http://127.0.0.1:9180/apisix/admin/services/200 \
                                                                -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d '
                                                {
                                                    "upstream": {
                                                        "type": "roundrobin",
                                                        "nodes": {
                                                      "httpbin.org:80": 1
                                                        }
                                                    }
                                                }'
{"value":{"create_time":1691050434,"upstream":{"nodes":{"httpbin.org:80":1},"type":"roundrobin","hash_on":"vars","scheme":"http","pass_host":"pass"},"update_time":1691050434,"id":"200"},"key":"/apisix/services/200"}
~/w/apisix> curl http://127.0.0.1:9180/apisix/admin/routes/100 \
                                                -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d '
                                    {
                                        "methods": ["GET"],
                                        "uri": "/anything",
                                        "service_id": "200"
                                    }'
{"value":{"uri":"/anything","create_time":1691050439,"priority":0,"id":"100","methods":["GET"],"service_id":"200","update_time":1691050439,"status":1},"key":"/apisix/routes/100"}

and test the router.

~/w/apisix> curl http://localhost:9080/anything -v
* processing: http://localhost:9080/anything
*   Trying [::1]:9080...
* Connected to localhost (::1) port 9080
> GET /anything HTTP/1.1
> Host: localhost:9080
> User-Agent: curl/8.2.1
> Accept: */*
>

< HTTP/1.1 200 OK
< Content-Type: application/json
< Content-Length: 382
< Connection: keep-alive
< Date: Thu, 03 Aug 2023 08:14:28 GMT
< Access-Control-Allow-Origin: *
< Access-Control-Allow-Credentials: true
< Server: APISIX/3.2.2
<
{
  "args": {},
  "data": "",
  "files": {},
  "form": {},
  "headers": {
    "Accept": "*/*",
    "Host": "localhost",
    "User-Agent": "curl/8.2.1",
    "X-Amzn-Trace-Id": "Root=1-64cb61e0-5e4919de62e639d160823fde",
    "X-Forwarded-Host": "localhost"
  },
  "json": null,
  "method": "GET",
  "origin": "::1, 220.246.124.214",
  "url": "http://localhost/anything"
}
* Connection #0 to host localhost left intact

Now it works.

check out 3.2.1

check out the tag 3.2.1 and make reload

~/w/apisix> git co 3.2.1
Previous HEAD position was 77704832 feat: release APISIX 3.2.2 (#9723)
HEAD is now at f81a386d feat: release apisix 3.2.1 (#9559)
~/w/apisix> make deps
Wrote
	variables.OPENSSL_LIBDIR = "/opt/homebrew/opt/openresty-openssl111/lib"
to
	/Users/guohao/.luarocks/config-5.1.lua
Wrote
	variables.OPENSSL_INCDIR = "/opt/homebrew/opt/openresty-openssl111/include"
to
	/Users/guohao/.luarocks/config-5.1.lua
Missing dependencies for apisix master-0:
   api7-lua-resty-jwt 0.2.4 (not installed)

apisix master-0 depends on lua-resty-ctxdump 0.1-0 (0.1-0 installed)
apisix master-0 depends on api7-lua-resty-dns-client 7.0.1 (7.0.1-0 installed)
apisix master-0 depends on lua-resty-template 2.0 (2.0-1 installed)
apisix master-0 depends on lua-resty-etcd 1.10.4 (1.10.4-0 installed)
apisix master-0 depends on api7-lua-resty-http 0.2.0 (0.2.0-0 installed)
apisix master-0 depends on lua-resty-balancer 0.04 (0.04-0 installed)
apisix master-0 depends on lua-resty-ngxvar 0.5.2 (0.5.2-0 installed)
apisix master-0 depends on lua-resty-jit-uuid 0.0.7 (0.0.7-2 installed)
apisix master-0 depends on lua-resty-healthcheck-api7 2.2.2 (2.2.2-0 installed)
apisix master-0 depends on api7-lua-resty-jwt 0.2.4 (not installed)
Installing https://luarocks.org/api7-lua-resty-jwt-0.2.4-0.src.rock

api7-lua-resty-jwt 0.2.4-0 depends on lua >= 5.1 (5.1-1 provided by VM)
api7-lua-resty-jwt 0.2.4-0 depends on lua-resty-openssl >= 0.6.8 (0.8.22-1 installed)
api7-lua-resty-jwt 0.2.4-0 is now installed in /Users/guohao/workspace/apisix/deps (license: Apache License Version 2)

Checking stability of dependencies in the absence of
api7-lua-resty-jwt 0.2.5-0...

Removing api7-lua-resty-jwt 0.2.5-0...
Removal successful.
apisix master-0 depends on lua-resty-hmac-ffi 0.05 (0.05-0 installed)
apisix master-0 depends on lua-resty-cookie 0.1.0 (0.1.0-2 installed)
apisix master-0 depends on lua-resty-session 3.10 (3.10-1 installed)
apisix master-0 depends on opentracing-openresty 0.1 (0.1-0 installed)
apisix master-0 depends on lua-resty-radixtree 2.8.2 (2.8.2-0 installed)
apisix master-0 depends on lua-protobuf 0.4.1 (0.4.1-1 installed)
apisix master-0 depends on lua-resty-openidc 1.7.5 (1.7.5-1 installed)
apisix master-0 depends on luafilesystem 1.7.0-2 (1.7.0-2 installed)
apisix master-0 depends on api7-lua-tinyyaml 0.4.2 (0.4.2-0 installed)
apisix master-0 depends on nginx-lua-prometheus 0.20220527 (0.20220527-1 installed)
apisix master-0 depends on jsonschema 0.9.8 (0.9.8-0 installed)
apisix master-0 depends on lua-resty-ipmatcher 0.6.1 (0.6.1-0 installed)
apisix master-0 depends on lua-resty-kafka 0.20-0 (0.20-0 installed)
apisix master-0 depends on lua-resty-logger-socket 2.0.1-0 (2.0.1-0 installed)
apisix master-0 depends on skywalking-nginx-lua 0.6.0 (0.6.0-0 installed)
apisix master-0 depends on base64 1.5-2 (1.5-2 installed)
apisix master-0 depends on binaryheap 0.4 (0.4-1 installed)
apisix master-0 depends on api7-dkjson 0.1.1 (0.1.1-0 installed)
apisix master-0 depends on resty-redis-cluster 1.02-4 (1.02-4 installed)
apisix master-0 depends on lua-resty-expr 1.3.2 (1.3.2-0 installed)
apisix master-0 depends on graphql 0.0.2 (0.0.2-1 installed)
apisix master-0 depends on argparse 0.7.1-1 (0.7.1-1 installed)
apisix master-0 depends on luasocket 3.1.0-1 (3.1.0-1 installed)
apisix master-0 depends on luasec 0.9-1 (0.9-1 installed)
apisix master-0 depends on lua-resty-consul 0.3-2 (0.3-2 installed)
apisix master-0 depends on penlight 1.9.2-1 (1.9.2-1 installed)
apisix master-0 depends on ext-plugin-proto 0.6.0 (0.6.0-0 installed)
apisix master-0 depends on casbin 1.41.5 (1.41.5-1 installed)
apisix master-0 depends on api7-snowflake 2.0-1 (2.0-1 installed)
apisix master-0 depends on inspect 3.1.1 (3.1.1-0 installed)
apisix master-0 depends on lualdap 1.2.6-1 (1.2.6-1 installed)
apisix master-0 depends on lua-resty-rocketmq 0.3.0-0 (0.3.0-0 installed)
apisix master-0 depends on opentelemetry-lua 0.2-3 (0.2-3 installed)
apisix master-0 depends on net-url 0.9-1 (0.9-1 installed)
apisix master-0 depends on xml2lua 1.5-2 (1.5-2 installed)
apisix master-0 depends on nanoid 0.1-1 (0.1-1 installed)
apisix master-0 depends on lua-resty-mediador 0.1.2-1 (0.1.2-1 installed)
apisix master-0 depends on lua-resty-ldap 0.1.0-0 (0.1.0-0 installed)
Stopping after installing dependencies for apisix master-0

~/w/apisix> make reload
[ info ] reload -> [ Start ]
/Users/guohao/workspace/apisix/bin/apisix reload
/usr/local/openresty//luajit/bin/luajit ./apisix/cli/apisix.lua reload
[ info ] reload -> [ Done ]

test the router

~/w/apisix> curl http://localhost:9080/anything -v
* processing: http://localhost:9080/anything
*   Trying [::1]:9080...
* Connected to localhost (::1) port 9080
> GET /anything HTTP/1.1
> Host: localhost:9080
> User-Agent: curl/8.2.1
> Accept: */*
>
< HTTP/1.1 404 Not Found
< Date: Thu, 03 Aug 2023 08:14:56 GMT
< Content-Type: text/plain; charset=utf-8
< Transfer-Encoding: chunked
< Connection: keep-alive
< Server: APISIX/3.2.1
<
{"error_msg":"404 Route Not Found"}
* Connection #0 to host localhost left intact

check the etcd

~/w/apisix> etcdctl get /apisix/routes/100
/apisix/routes/100
{"uri":"/anything","service_id":"200","priority":0,"id":"100","create_time":1691050439,"methods":["GET"],"update_time":1691050439,"status":1}
~/w/apisix> etcdctl get /apisix/services/200
/apisix/services/200
{"create_time":1691050434,"upstream":{"nodes":{"httpbin.org:80":1},"type":"roundrobin","hash_on":"vars","scheme":"http","pass_host":"pass"},"update_time":1691050434,"id":"200"}

@Sn0rt
Copy link
Contributor

Sn0rt commented Aug 3, 2023

check the etcd

~/w/apisix> etcdctl get /apisix/routes/100
/apisix/routes/100
{"uri":"/anything","service_id":"200","priority":0,"id":"100","create_time":1691050439,"methods":["GET"],"update_time":1691050439,"status":1}
~/w/apisix> etcdctl get /apisix/services/200
/apisix/services/200
{"create_time":1691050434,"upstream":{"nodes":{"httpbin.org:80":1},"type":"roundrobin","hash_on":"vars","scheme":"http","pass_host":"pass"},"update_time":1691050434,"id":"200"}

format the result /apisix/routes/100

{
  "uri": "/anything",
  "service_id": "200",
  "priority": 0,
  "id": "100",
  "create_time": 1691050439,
  "methods": [
    "GET"
  ],
  "update_time": 1691050439,
  "status": 1
}

the /apisix/services/200

{
  "create_time": 1691050434,
  "upstream": {
    "nodes": {
      "httpbin.org:80": 1
    },
    "type": "roundrobin",
    "hash_on": "vars",
    "scheme": "http",
    "pass_host": "pass"
  },
  "update_time": 1691050434,
  "id": "200"
}

@wklken
Copy link
Author

wklken commented Aug 3, 2023

@Sn0rt I am not sure your reproduce step is correct


my step is:

  1. use 3.2.1, crate route/service, 200
  2. upgrade to 3.2.2, create route/service, 404, apisix reload, 200, create another route/service, 404; (and in the error.log got not error, it seems the apisix did not watched the changes)

the 3.2.1 is ok(we deployed on production for a long time), only the 3.2.2 has the 404 issue;

@Sn0rt
Copy link
Contributor

Sn0rt commented Aug 3, 2023

  • use 3.2.1, crate route/service, 200

So can you simplify the environment to reproduce? I'm checking my steps to reproduce.

I don't quite understand what you describe, it is best to provide certain steps to reproduce.

upgrade to 3.2.2, create route/service, 404, apisix reload, 200, create another route/service, 404; (and in the error.log got not error, it seems the apisix did not watched the changes)

Can you explain what this means?

@wklken
Copy link
Author

wklken commented Aug 3, 2023

@Sn0rt I have reproduce it via docker-compose; the key is change the deployment.etcd.prefix!


the steps:

  1. git clone https://github.com/apache/apisix-docker.git
  2. cd apisix-docker/compose
  3. edit the docker-compose-master.yaml
version: "3"

services:
  apisix:
    # image: "apache/apisix:${APISIX_DOCKER_TAG}"
    image: "apache/apisix:3.2.2-centos"
    restart: always
    volumes:
      - ./apisix_conf/master/config.yaml:/usr/local/apisix/conf/config.yaml:ro
    depends_on:
      - etcd
    ports:
      - "9180:9180/tcp"
      - "9080:9080/tcp"
      - "9091:9091/tcp"
      - "9443:9443/tcp"
    networks:
      - apisix

  etcd:
    image: bitnami/etcd:3.5.7
    # user: root
    # restart: always
    volumes:
      - ../example/etcd_data:/bitnami/etcd_data
        # volumes:
        #   - etcd_data:/bitnami/etcd
    environment:
      ETCD_DATA_DIR: /etcd_data
      ETCD_ENABLE_V2: "true"
      ALLOW_NONE_AUTHENTICATION: "yes"
      ETCD_ADVERTISE_CLIENT_URLS: "http://0.0.0.0:2379"
      ETCD_LISTEN_CLIENT_URLS: "http://0.0.0.0:2379"
    ports:
      - "2379:2379/tcp"
    networks:
      - apisix

networks:
  apisix:
    driver: bridge
  1. edit the apisix_conf/master/config.yaml
apisix:
  node_listen: 9080              # APISIX listening port
  enable_ipv6: false

  router:
    http: radixtree_uri_with_parameter

nginx_config:
  http:
    enable_access_log: false
    client_max_body_size: "40m"

  error_log_level: "info"
  worker_processes: 1

deployment:
  admin:
    allow_admin:               # https://nginx.org/en/docs/http/ngx_http_access_module.html#allow
      - 0.0.0.0/0              # We need to restrict ip access rules for security. 0.0.0.0/0 is for test.

    admin_key:
      - name: "admin"
        key: edd1c9f034335f136f87ad84b625c8f1
        role: admin                 # admin: manage all configuration data

  etcd:
    host:                           # it's possible to define multiple etcd hosts addresses of the same etcd cluster.
      - "http://etcd:2379"          # multiple etcd address
    prefix: "/test-apisix"               # apisix configurations prefix
    timeout: 120                    # 30 seconds
  1. rm -rf ../example/etcd_data/*
  2. docker-compose -p docker-apisix -f docker-compose-master.yaml up
  3. open another terminal, docker ps -a get the running container id of apisix
  4. docker exec -it {the id} /bin/bash
  5. register the route and service
curl http://127.0.0.1:9180/apisix/admin/services/200 \
                                                                -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d '
                                                {
                                                    "upstream": {
                                                        "type": "roundrobin",
                                                        "nodes": {
                                                      "etcd:2379": 1
                                                        }
                                                    }
                                                }'
curl http://127.0.0.1:9180/apisix/admin/routes/100 \
                                                -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d '
                                    {
                                        "methods": ["GET"],
                                        "uri": "/metrics",
                                        "service_id": "200"
                                    }'
  1. there got no watch logs for the route and resource
  2. curl, got 404 curl http://localhost:9080/metrics -v

if you start from the beginning, change the prefix back to /apisix in the step 4 , then step 12 will got 200

@kingluo
Copy link
Contributor

kingluo commented Aug 3, 2023

@wklken It's not supposed to change prefix at the runtime, even if followed by apisix reload.
In the current implementation, a brand-new of keys layout of etcd prefix is required to be initiated either by apisix init, apistx start, or apisix restart, but not by apisix reload.

@wklken
Copy link
Author

wklken commented Aug 3, 2023

@kingluo when we change the prefix in config.yaml then start the apisix, the execution order is apisix start(prefix=/apisix) then apisix reload(prefix=/custom-prefix)?


change the prefix in config.yaml, then docker-compose up, put a route and service, the config_etcd.lua got the events, but still 404

apisix_1  | 2023/08/03 14:14:50 [info] 51#51: *16 [lua] config_etcd.lua:117: produce_res(): append res: {
apisix_1  |   result = {
apisix_1  |     events = { {
apisix_1  |         kv = {
apisix_1  |           create_revision = "45",
apisix_1  |           key = "/test-apisix/routes/100",
apisix_1  |           mod_revision = "45",
apisix_1  |           value = {
apisix_1  |             create_time = 1691072090,
apisix_1  |             id = "100",
apisix_1  |             methods = { "GET",
apisix_1  |               <metatable> = <1>{}
apisix_1  |             },
apisix_1  |             priority = 0,
apisix_1  |             service_id = "200",
apisix_1  |             status = 1,
apisix_1  |             update_time = 1691072090,
apisix_1  |             uri = "/metrics"
apisix_1  |           },
apisix_1  |           version = "1"
apisix_1  |         }
apisix_1  |       },
apisix_1  |       <metatable> = <table 1>
apisix_1  |     },
apisix_1  |     header = {1qapisix_1  |       cluster_id = "14841639068965178418",
apisix_1  |       member_id = "10276657743932975437",
apisix_1  |       raft_term = "5",
apisix_1  |       revision = "45"
apisix_1  |     }
apisix_1  |   }
apisix_1  | }, err: nil, context: ngx.timer


# and wait for few minutes, there are some err: timeout

apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *28 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/global_rules prev_index: 43, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *28 [lua] config_etcd.lua:628: sync_data(): res: null, err: timeout, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *29 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/services prev_index: 43, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *29 [lua] config_etcd.lua:628: sync_data(): res: null, err: timeout, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *30 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/plugin_configs prev_index: 43, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *30 [lua] config_etcd.lua:628: sync_data(): res: null, err: timeout, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *31 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/consumers prev_index: 43, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *31 [lua] config_etcd.lua:628: sync_data(): res: null, err: timeout, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *32 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/consumer_groups prev_index: 43, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *32 [lua] config_etcd.lua:628: sync_data(): res: null, err: timeout, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *33 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/secrets prev_index: 43, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *33 [lua] config_etcd.lua:628: sync_data(): res: null, err: timeout, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *34 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/upstreams prev_index: 43, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *34 [lua] config_etcd.lua:628: sync_data(): res: null, err: timeout, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *24 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/protos prev_index: 43, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *24 [lua] config_etcd.lua:628: sync_data(): res: null, err: timeout, context: ngx.timer
apisix_1  | 2023/08/03 14:28:40 [info] 48#48: *26 [lua] config_etcd.lua:627: sync_data(): waitdir key: /test-apisix/routes prev_index: 43, context: ngx.timer

@kingluo
Copy link
Contributor

kingluo commented Aug 3, 2023

@wklken
apisix start has nothing to do with apisix reload, the previous one implies etcd layout initialization under the prefix.
To simplify the scenario, please keep the prefix unchanged and try to reproduce the issue.
It's better to keep those steps stable. It seems you talked about multiple scenarios with only a little of differences, which confused me a bit.
Tell me the final version of the full and detailed steps and I'll try to check it sooner or later. Thanks.

@jiangfucheng jiangfucheng assigned jiangfucheng and unassigned Sn0rt Aug 3, 2023
@jiangfucheng
Copy link
Member

jiangfucheng commented Aug 3, 2023

https://github.com/apache/apisix/blob/f99cf546d4a514f73870073cf3e3bfeb598a5777/apisix/core/config_etcd.lua#L395C30-L395C30
I reproduced this bug, It seems causes by this code, string.find() method default is pattern matching, “-” is a special character.

ref: https://www.lua.org/manual/5.1/manual.html#pdf-string.find

@wklken
Copy link
Author

wklken commented Aug 3, 2023

@wklken apisix start has nothing to do with apisix reload, the previous one implies etcd layout initialization under the prefix. To simplify the scenario, please keep the prefix unchanged and try to reproduce the issue. It's better to keep those steps stable. It seems you talked about multiple scenarios with only a little of differences, which confused me a bit. Tell me the final version of the full and detailed steps and I'll try to check it sooner or later. Thanks.

@kingluo

sorry for the confusing words in the reproduce steps, I have changed it to if you start from the beginning, change the prefix back to /apisix in the step 4 , then step 12 will got 200, the steps is correct.

@wklken
Copy link
Author

wklken commented Aug 3, 2023

@jiangfucheng I have checked, if we remove the - from prefix, the 404 disappeared.

@monkeyDluffy6017
Copy link
Contributor

@jiangfucheng Excellent work!

@kingluo
Copy link
Contributor

kingluo commented Aug 4, 2023

https://github.com/apache/apisix/blob/f99cf546d4a514f73870073cf3e3bfeb598a5777/apisix/core/config_etcd.lua#L395C30-L395C30 I reproduced this bug, It seems causes by this code, string.find() method default is pattern matching, “-” is a special character.

ref: https://www.lua.org/manual/5.1/manual.html#pdf-string.find

@jiangfucheng
Yes, it's a bug. Thanks for your bugfix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working wait for update wait for the author's response in this issue/PR
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

7 participants