You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@apisix.apache.org by GitBox <gi...@apache.org> on 2022/12/01 02:50:30 UTC
[GitHub] [apisix] hansedong opened a new issue, #8436: bug: mutil upstream and status in apisix log
hansedong opened a new issue, #8436:
URL: https://github.com/apache/apisix/issues/8436
### Current Behavior
In the apisix log, multiple records appear in the upstream and upstream_status fields:
```
{
"msec": 1669861681.376,
"request_id": "b2334ca98e7bd7016caf79d9d606f0fe",
"request_length": "13896",
"request_time": "33.093",
"request_uri": "/list-risk",
"request_method": "GET",
"remote_addr": "192.168.13.64",
"remote_user": "",
"remote_port": "34927",
"time_iso8601": "2022-12-01T10:28:01+08:00",
"args": "",
"status": "502",
"body_bytes_sent": "556",
"bytes_sent": "758",
"hostname": "knode15-166",
"http_referer": "https://xxxx.com/user/info",
"http_user_agent": "User-Agent: Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; 360SE)",
"http_x_forwarded_for": "103.246.244.35",
"http_host": "src.host",
"upstream": "192.168.84.159:80, 192.168.84.163:80",
"upstream_status": "504, 502",
"upstream_connect_time": "0.001, -",
"upstream_header_time": "-, -",
"upstream_response_time": "30.001, 3.092",
"upstream_response_length": "0, 0",
"upstream_cache_status": "",
"ssl_protocol": "",
"ssl_cipher": "",
"scheme": "http",
"server_protocol": "HTTP/1.1",
"server_addr": "10.132.63.60",
"server_port": "80"
}
```
> It can be seen that the content of upstream_status and upstream are multiple values
The following is the format of apisix log:
```
access_log_format: "{\"msec\":$msec,\"request_id\":\"$request_id\",\"request_length\":\"$request_length\",\"request_time\":\"$request_time\",\"request_uri\":\"$request_uri\",\"request_method\":\"$request_method\",\"remote_addr\":\"$remote_addr\",\"remote_user\":\"$remote_user\",\"remote_port\":\"$remote_port\",\"time_iso8601\":\"$time_iso8601\",\"args\":\"$args\",\"status\":\"$status\",\"body_bytes_sent\":\"$body_bytes_sent\",\"bytes_sent\":\"$bytes_sent\",\"hostname\":\"$hostname\",\"http_referer\":\"$http_referer\",\"http_user_agent\":\"$http_user_agent\",\"http_x_forwarded_for\":\"$http_x_forwarded_for\",\"http_host\":\"$http_host\",\"upstream\":\"$upstream_addr\",\"upstream_status\":\"$upstream_status\",\"upstream_connect_time\":\"$upstream_connect_time\",\"upstream_header_time\":\"$upstream_header_time\",\"upstream_response_time\":\"$upstream_response_time\",\"upstream_response_length\":\"$upstream_response_length\",\"upstream_cache_status\":\"$upstream_cache_status\",\"ssl_p
rotocol\":\"$ssl_protocol\",\"ssl_cipher\":\"$ssl_cipher\",\"scheme\":\"$scheme\",\"server_protocol\":\"$server_protocol\",\"server_addr\":\"$server_addr\",\"server_port\":\"$server_port\"}"
```
The apisix upstream is:
```
{
"nodes": [
{
"host": "192.168.84.159",
"port": 80,
"weight": 10
},
{
"host": "192.168.84.163",
"port": 80,
"weight": 10
}
],
"timeout": {
"connect": 6,
"send": 30,
"read": 30
},
"type": "roundrobin",
"hash_on": "vars",
"scheme": "http",
"pass_host": "pass",
"name": "ms-aos-src-host-product-gp-399309-80",
"desc": "upstream for appcode: src-mservice and version: 399309",
"labels": {
"appcode": "src-host",
"env-type": "product",
"version": "399309"
}
}
```
the apisix route is:
```
{
"uris": [
"/*"
],
"name": "ms-aos-host-product-gp",
"desc": "route for appcode: src-host",
"priority": 1985221842,
"methods": [
"GET",
"POST",
"PUT",
"DELETE",
"PATCH",
"HEAD",
"OPTIONS",
"CONNECT",
"TRACE"
],
"hosts": [
"src.host"
],
"remote_addrs": [
"0.0.0.0/0"
],
"plugins": {
"client-control": {
"disable": false,
"max_body_size": 268435456
},
"prometheus": {
"disable": false,
"prefer_name": false
},
"response-rewrite": {
"body_base64": false,
"disable": false,
"headers": {
"server": "gateway"
}
},
"traffic-split": {
"disable": false,
"rules": [
{
"match": [
{
"vars": [
[
"request_uri",
"~~",
"^/(.*?)$"
]
]
}
],
"weighted_upstreams": [
{
"upstream_id": "ms-aos-src-host-product-gp-399309-80",
"weight": 100
}
]
}
]
}
},
"upstream_id": "ms-aos-src-host-product-gp-399309-80",
"labels": {
"app-code": "src-host",
"env-type": "product"
},
"enable_websocket": true,
"status": 1
}
```
### Expected Behavior
According to my understanding, there should only be one upstream_status and upstream.
### Error Logs
_No response_
### Steps to Reproduce
I don't know how to reproduce this situation, I want to know 2 points:
1. how does this happen?
2. does this mean that apisix made requests to 2 upstreams at the same time?
### Environment
- APISIX version (run `apisix version`): `2.13.2`
- Operating system (run `uname -a`): `Linux knode10-132-14-166 4.19.91-26.al7.x86_64 #1 SMP Tue May 24 12:11:55 CST 2022 x86_64 x86_64 x86_64 GNU/Linux`
- OpenResty / Nginx version (run `openresty -V` or `nginx -V`):
```
nginx version: openresty/1.21.4.1
built by gcc 9.3.1 20200408 (Red Hat 9.3.1-2) (GCC)
built with OpenSSL 1.1.1n 15 Mar 2022
TLS SNI support enabled
configure arguments: --prefix=/usr/local/openresty/nginx --with-cc-opt='-O2 -DAPISIX_BASE_VER=1.21.4.1.0 -DNGX_LUA_ABORT_AT_PANIC -I/usr/local/openresty/zlib/include -I/usr/local/openresty/pcre/include -I/usr/local/openresty/openssl111/include' --add-module=../ngx_devel_kit-0.3.1 --add-module=../echo-nginx-module-0.62 --add-module=../xss-nginx-module-0.06 --add-module=../ngx_coolkit-0.2 --add-module=../set-misc-nginx-module-0.33 --add-module=../form-input-nginx-module-0.12 --add-module=../encrypted-session-nginx-module-0.09 --add-module=../srcache-nginx-module-0.32 --add-module=../ngx_lua-0.10.21 --add-module=../ngx_lua_upstream-0.07 --add-module=../headers-more-nginx-module-0.33 --add-module=../array-var-nginx-module-0.05 --add-module=../memc-nginx-module-0.19 --add-module=../redis2-nginx-module-0.15 --add-module=../redis-nginx-module-0.3.9 --add-module=../ngx_stream_lua-0.0.11 --with-ld-opt='-Wl,-rpath,/usr/local/openresty/luajit/lib -Wl,-rpath,/usr/local/openresty/wasmtime-c-ap
i/lib -L/usr/local/openresty/zlib/lib -L/usr/local/openresty/pcre/lib -L/usr/local/openresty/openssl111/lib -Wl,-rpath,/usr/local/openresty/zlib/lib:/usr/local/openresty/pcre/lib:/usr/local/openresty/openssl111/lib' --add-module=/tmp/tmp.jxGTHHB5bC/openresty-1.21.4.1/../mod_dubbo-1.0.2 --add-module=/tmp/tmp.jxGTHHB5bC/openresty-1.21.4.1/../ngx_multi_upstream_module-1.1.0 --add-module=/tmp/tmp.jxGTHHB5bC/openresty-1.21.4.1/../apisix-nginx-module-1.9.0 --add-module=/tmp/tmp.jxGTHHB5bC/openresty-1.21.4.1/../apisix-nginx-module-1.9.0/src/stream --add-module=/tmp/tmp.jxGTHHB5bC/openresty-1.21.4.1/../apisix-nginx-module-1.9.0/src/meta --add-module=/tmp/tmp.jxGTHHB5bC/openresty-1.21.4.1/../wasm-nginx-module-0.6.1 --add-module=/tmp/tmp.jxGTHHB5bC/openresty-1.21.4.1/../lua-var-nginx-module-v0.5.2 --with-poll_module --with-pcre-jit --with-stream --with-stream_ssl_module --with-stream_ssl_preread_module --with-http_v2_module --without-mail_pop3_module --without-mail_imap_module --without-mail_
smtp_module --with-http_stub_status_module --with-http_realip_module --with-http_addition_module --with-http_auth_request_module --with-http_secure_link_module --with-http_random_index_module --with-http_gzip_static_module --with-http_sub_module --with-http_dav_module --with-http_flv_module --with-http_mp4_module --with-http_gunzip_module --with-threads --with-compat --with-stream --with-http_ssl_module
```
- etcd version, if relevant (run `curl http://127.0.0.1:9090/v1/server_info`): `{"version":"2.13.2","boot_time":1666694341,"etcd_version":"3.5.0","id":"668381fb-6fbe-476a-a61d-3715a87903ad","hostname":"knode10-132-14-166"}`
- APISIX Dashboard version, if relevant:
- Plugin runner version, for issues related to plugin runners:
- LuaRocks version, for installation issues (run `luarocks --version`):
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] hansedong commented on issue #8436: bug: mutil upstream and upstream_status values in apisix log
Posted by GitBox <gi...@apache.org>.
hansedong commented on issue #8436:
URL: https://github.com/apache/apisix/issues/8436#issuecomment-1334726902
@spacewander
However, I did not enable the retry strategy in the upstream configuration. You can see the upstream json data copyed from the apisix dashboard:
```
{
"nodes": [
{
"host": "192.168.84.159",
"port": 80,
"weight": 10
},
{
"host": "192.168.84.163",
"port": 80,
"weight": 10
}
],
"timeout": {
"connect": 6,
"send": 30,
"read": 30
},
"type": "roundrobin",
"hash_on": "vars",
"scheme": "http",
"pass_host": "pass",
"name": "ms-aos-src-host-product-gp-399309-80",
"desc": "upstream for appcode: src-mservice and version: 399309",
"labels": {
"appcode": "src-host",
"env-type": "product",
"version": "399309"
}
}
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] hansedong commented on issue #8436: bug: mutil upstream and upstream_status values in apisix log
Posted by GitBox <gi...@apache.org>.
hansedong commented on issue #8436:
URL: https://github.com/apache/apisix/issues/8436#issuecomment-1334730097
```
{
"msec": 1669861681.376,
"request_id": "b2334ca98e7bd7016caf79d9d606f0fe",
"request_length": "13896",
"request_time": "33.093",
"request_uri": "/list-risk",
"request_method": "GET",
"remote_addr": "192.168.13.64",
"remote_user": "",
"remote_port": "34927",
"time_iso8601": "2022-12-01T10:28:01+08:00",
"args": "",
"status": "502",
"body_bytes_sent": "556",
"bytes_sent": "758",
"hostname": "knode15-166",
"http_referer": "https://xxxx.com/user/info",
"http_user_agent": "User-Agent: Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; 360SE)",
"http_x_forwarded_for": "103.246.244.35",
"http_host": "src.host",
"upstream": "192.168.84.159:80, 192.168.84.163:80",
"upstream_status": "504, 502",
"upstream_connect_time": "0.001, -",
"upstream_header_time": "-, -",
"upstream_response_time": "30.001, 3.092",
"upstream_response_length": "0, 0",
"upstream_cache_status": "",
"ssl_protocol": "",
"ssl_cipher": "",
"scheme": "http",
"server_protocol": "HTTP/1.1",
"server_addr": "10.132.63.60",
"server_port": "80"
}
```
@spacewander You can see that the timeout period I configured is 30s, and there is such a message in the log
```
"upstream_response_time": "30.001, 3.092",
```
It seems that after the first request upstream times out, the second one is requested. Is there any configuration for apisix to turn off this request mechanism?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] hansedong commented on issue #8436: bug: mutil upstream and upstream_status values in apisix log
Posted by GitBox <gi...@apache.org>.
hansedong commented on issue #8436:
URL: https://github.com/apache/apisix/issues/8436#issuecomment-1334819085
@spacewander
```
Set according to the number of available backend nodes by default.
```
I got it, thanks very much.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] spacewander commented on issue #8436: bug: mutil upstream and upstream_status values in apisix log
Posted by GitBox <gi...@apache.org>.
spacewander commented on issue #8436:
URL: https://github.com/apache/apisix/issues/8436#issuecomment-1334816597
The retry is enabled by default. See https://github.com/apache/apisix/blob/master/docs/en/latest/admin-api.md#request-body-parameters-3
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] spacewander commented on issue #8436: bug: mutil upstream and upstream_status values in apisix log
Posted by GitBox <gi...@apache.org>.
spacewander commented on issue #8436:
URL: https://github.com/apache/apisix/issues/8436#issuecomment-1333248441
There can be multiple upstream_xxx values when retrying happened.
See http://nginx.org/en/docs/http/ngx_http_upstream_module.html#var_upstream_addr
> If several servers were contacted during request processing, their addresses are separated by commas, e.g. “192.168.1.1:80, 192.168.1.2:80, unix:/tmp/sock”.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [apisix] hansedong closed issue #8436: bug: mutil upstream and upstream_status values in apisix log
Posted by GitBox <gi...@apache.org>.
hansedong closed issue #8436: bug: mutil upstream and upstream_status values in apisix log
URL: https://github.com/apache/apisix/issues/8436
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: notifications-unsubscribe@apisix.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org