apache
bug: API disabled in the context of body_filter_by_lua*
Current Behavior
When the java plug-in ext-plugin-post-resp is used, API disabled occurs when the response body is large. in the context of body_filter_by_lua*, however, there is no problem on the local computer. Deploy the program to the server and it will appear. Error message:
lua entry thread aborted: runtime error: /usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:109: API disabled in the context of body_filter_by_lua*
stack traceback:
coroutine 0:
[C]: in function 'ngx_print'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:109: in function 'send_chunk'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:132: in function 'send_response'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:171: in function 'phase_func'
/usr/local/apisix/apisix/plugin.lua:1097: in function 'common_phase'
/usr/local/apisix/apisix/init.lua:507: in function 'handle_upstream'
/usr/local/apisix/apisix/init.lua:669: in function 'http_access_phase'
access_by_lua(nginx.conf:334):2: in main chunk, client: 11.18.1.47, server: _, request: "POST /1122/o8k8yu/jrsoap/soa/TradeInfoService HTTP/1.1"
Plug-in code:
package cn.devops.plugin.filter;
import cn.devops.plugin.constant.CacheNameTimeConstant;
import cn.devops.plugin.constant.GatewayConstants;
import cn.hutool.core.util.ObjectUtil;
import cn.hutool.core.util.StrUtil;
import lombok.extern.slf4j.Slf4j;
import org.apache.apisix.plugin.runner.HttpRequest;
import org.apache.apisix.plugin.runner.HttpResponse;
import org.apache.apisix.plugin.runner.PostRequest;
import org.apache.apisix.plugin.runner.PostResponse;
import org.apache.apisix.plugin.runner.filter.PluginFilterChain;
import org.springframework.cache.Cache;
import org.springframework.cache.CacheManager;
import org.springframework.data.redis.core.RedisTemplate;
import org.w3c.dom.Document;
import org.w3c.dom.Element;
import org.w3c.dom.NodeList;
import org.xml.sax.InputSource;
import javax.annotation.Resource;
import javax.xml.parsers.DocumentBuilder;
import javax.xml.parsers.DocumentBuilderFactory;
import java.io.StringReader;
import java.net.URL;
import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.TimeUnit;
@Slf4j
public class WebServiceResponseRewritePluginFilter extends BaseGatewayPluginFilter {
@Resource
private CacheManager cacheManager;
@Resource(name = "gatewayRedisTemplate")
private RedisTemplate<String, Object> gatewayRedisTemplate;
@Override
public String name() {
return "web-service-response-rewrite";
}
@Override
public void filter(HttpRequest request, HttpResponse response, PluginFilterChain chain) {
String host = request.getHeader("host");
String requestId = request.getVars("request_id");
gatewayRedisTemplate.opsForValue().set(GatewayConstants.getGatewayRequestHostKey(requestId),
host, 30, TimeUnit.MINUTES);
Cache cache = cacheManager.getCache(CacheNameTimeConstant.CACHE_REQUEST_HOST);
if (ObjectUtil.isNotNull(cache)) {
cache.put(requestId, host);
}
chain.filter(request, response);
}
@Override
public void postFilter(PostRequest request, PostResponse response, PluginFilterChain chain) {
String requestId = request.getVars("request_id");
boolean isWsdlXml = false;
String requestUri = request.getVars("request_uri");
if (StrUtil.contains(requestUri, "wsdl")) {
isWsdlXml = true;
}
if (!isWsdlXml) {
chain.postFilter(request, response);
return;
}
String host = null;
Cache cache = cacheManager.getCache(CacheNameTimeConstant.CACHE_REQUEST_HOST);
if (ObjectUtil.isNotNull(cache)) {
host = cache.get(requestId, String.class);
}
if (StrUtil.isBlank(host)) {
host = (String) gatewayRedisTemplate.opsForValue()
.get(GatewayConstants.getGatewayRequestHostKey(requestId));
}
if (StrUtil.isBlank(host)) {
chain.postFilter(request, response);
return;
}
String newLocation = StrUtil.subBefore(requestUri, "?", false);
try {
DocumentBuilderFactory dbFactory = DocumentBuilderFactory.newInstance();
DocumentBuilder dBuilder = dbFactory.newDocumentBuilder();
InputSource inputSource = new InputSource(new StringReader(request.getBody()));
Document doc = dBuilder.parse(inputSource);
NodeList soapAddressList = doc.getElementsByTagName("soap:address");
if (soapAddressList.getLength() > 0) {
for (int i = 0; i < soapAddressList.getLength(); i++) {
Element soapAddressElement = (Element) soapAddressList.item(i);
String location = soapAddressElement.getAttribute("location");
URL url = new URL(location);
soapAddressElement.setAttribute("location",
url.getProtocol() + "://" + host + newLocation);
}
} else {
chain.postFilter(request, response);
return;
}
javax.xml.transform.TransformerFactory transformerFactory = javax.xml.transform.TransformerFactory.newInstance();
javax.xml.transform.Transformer transformer = transformerFactory.newTransformer();
javax.xml.transform.dom.DOMSource source = new javax.xml.transform.dom.DOMSource(doc);
java.io.StringWriter writer = new java.io.StringWriter();
javax.xml.transform.stream.StreamResult result = new javax.xml.transform.stream.StreamResult(writer);
transformer.transform(source, result);
String updatedXml = writer.toString();
response.setBody(updatedXml);
} catch (Exception e) {
log.error(e.getMessage(), e);
}
response.setHeader("Content-Type", "text/xml;charset=UTF-8");
chain.postFilter(request, response);
}
@Override
public List<String> requiredVars() {
List<String> vars = new ArrayList<>();
vars.add("remote_addr");
vars.add("server_port");
vars.add("request_id");
vars.add("request_uri");
vars.add("request_method");
vars.add("request_length");
vars.add("status");
return vars;
}
@Override
public Boolean requiredBody() {
return true;
}
@Override
public Boolean requiredRespBody() {
return true;
}
}
Expected Behavior
The upstream request response body was returned, but after using the plug-in, the request response body was truncated, and I suspect this error caused the data transfer to be interrupted
Error Logs
2023/08/22 10:34:27 [error] 65#65: *34548 lua entry thread aborted: runtime error: /usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:109: API disabled in the context of body_filter_by_lua*
stack traceback:
coroutine 0:
[C]: in function 'ngx_print'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:109: in function 'send_chunk'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:132: in function 'send_response'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:171: in function 'phase_func'
/usr/local/apisix/apisix/plugin.lua:1097: in function 'common_phase'
/usr/local/apisix/apisix/init.lua:507: in function 'handle_upstream'
/usr/local/apisix/apisix/init.lua:669: in function 'http_access_phase'
access_by_lua(nginx.conf:334):2: in main chunk, client: 11.18.1.47, server: _, request: "POST /1122/o8k8yu/jrsoap/soa/TradeInfoService HTTP/1.1", host: "xx.xxx.xx.xxx:10003"
11.18.1.47 - - [22/Aug/2023:10:34:27 +0800] xx.xxx.xx.xxx:10003 "POST /1122/o8k8yu/jrsoap/soa/TradeInfoService HTTP/1.1" 200 166436 0.757 "-" "PostmanRuntime-ApipostRuntime/1.1.0" - - - "http://xx.xxx.xx.xxx:10003/jrsoap/soa/TradeInfoService"
Steps to Reproduce
- Create a running apisix image based on the official apisix image, and add the java plug-in jar package to the image.
- Run the apisix docker image.
- Configure routes and add the java ext-plugin-post-resp plugin.
- Call the interface, simulate the request needs to return a relatively large packet, about about 1m.
- The response is truncated, and the apisix log output an error log.
Environment
- APISIX version (run
apisix version): 3.3.0 - Operating system (run
uname -a): Linux apisix-v1-765cb69475-8s4xq 3.10.0-1160.el7.x86_64 #1 SMP Mon Oct 19 16:18:59 UTC 2020 x86_64 GNU/Linux - OpenResty / Nginx version (run
openresty -Vornginx -V): openresty/1.21.4.1 - etcd version, if relevant (run
curl http://127.0.0.1:9090/v1/server_info): {"hostname":"apisix-v1-765cb69475-8s4xq","version":"3.3.0","etcd_version":"3.5.0","id":"cb46e64f-3cf9-47ad-819c-42183c9593e3","boot_time":1692671574} - APISIX Dashboard version, if relevant: 3.0.1
- Plugin runner version, for issues related to plugin runners: 0.4.0 for java
- LuaRocks version, for installation issues (run
luarocks --version):
After the log debugging is enabled, you can see that all packets are printed. However, after [id: 0x0c308141] READ COMPLETE, an error occurs with ext-plugin-post-resp.lua:109.
If it is a small request response body does not have this problem.
2023/08/22 11:32:01 [warn] 103#103: *240 [lua] init.lua:953: 6e 6f 74 69 63 65 4e 6f 64 65 5c 22 3a 5c |\"noticeNode\":\|
|0000baa0| 22 52 45 53 55 4c 54 5f 4e 4f 54 49 43 45 5c 22 |"RESULT_NOTICE\"|
|0000bab0| 2c 5c 22 50 4c 41 54 49 44 5c 22 3a 6e 75 6c 6c |,\"PLATID\":null|
|0000bac0| 7d 5d 22 7d 3c 2f 72 65 73 75 6c 74 3e 3c 2f 6e |}]"}</result></n|
|, context: ngx.timer
2023/08/22 11:32:01 [warn] 103#103: *240 [lua] init.lua:953: 0000bad0| 73 32 3a 51 75 65 72 79 5f 4e 6f 74 69 63 65 52 |s2:Query_NoticeR|
|0000bae0| 65 73 70 6f 6e 73 65 3e 3c 2f 73 6f 61 70 3a 42 |esponse></soap:B|
|0000baf0| 6f 64 79 3e 3c 2f 73 6f 61 70 3a 45 6e 76 65 6c |ody></soap:Envel|
|0000bb00| 6f 70 65 3e |ope> |
+--------+-------------------------------------------------+----------------+
, context: ngx.timer
2023/08/22 11:32:02 [warn] 103#103: *240 [lua] init.lua:953: 2023-08-22 03:32:02.042 DEBUG 228 --- [tLoopGroup-10-2] i.n.h.l.LoggingHandler : [id: 0x0c308141] WRITE: 24B
+-------------------------------------------------+
| 0 1 2 3 4 5 6 7 8 9 a b c d e f |
+--------+-------------------------------------------------+----------------+
|00000000| 04 00 00 14 0c 00 00 00 00 00 06 00 08 00 04 00 |................|
|00000010| 06 00 00 00 02 00 00 01 |........ |
+--------+-------------------------------------------------+----------------+
, context: ngx.timer
2023/08/22 11:32:02 [warn] 103#103: *240 [lua] init.lua:953: 2023-08-22 03:32:02.042 DEBUG 228 --- [tLoopGroup-10-2] i.n.h.l.LoggingHandler : [id: 0x0c308141] FLUSH
, context: ngx.timer
2023/08/22 11:32:02 [warn] 103#103: *240 [lua] init.lua:953: 2023-08-22 03:32:02.043 DEBUG 228 --- [tLoopGroup-10-2] i.n.h.l.LoggingHandler : [id: 0x0c308141] READ COMPLETE
, context: ngx.timer
2023/08/22 11:32:02 [error] 50#50: *51520 lua entry thread aborted: runtime error: /usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:109: API disabled in the context of body_filter_by_lua*
stack traceback:
coroutine 0:
[C]: in function 'ngx_print'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:109: in function 'send_chunk'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:132: in function 'send_response'
/usr/local/apisix/apisix/plugins/ext-plugin-post-resp.lua:171: in function 'phase_func'
/usr/local/apisix/apisix/plugin.lua:1097: in function 'common_phase'
/usr/local/apisix/apisix/init.lua:507: in function 'handle_upstream'
/usr/local/apisix/apisix/init.lua:669: in function 'http_access_phase'
access_by_lua(nginx.conf:334):2: in main chunk
Now that we have solved this problem, we have added response.setbody (request.getbody ()) to the first line of the postFilter method block, and there is no problem of the request response body being truncated.
But I don't understand why the response body of the request is normal when the packet is small.
现在已经解决这个问题，在postFilter 方法块第一行加入代码response.setBody(request.getBody())，没有出现请求响应体被截断的问题。 但是我不明白，为什么在数据包小的时候，请求的响应体的正常的。
I am still wondering about the error as to how did the ngx.print function got called in body_filter_by_lua phase when it's parent function is clearly called in access phase.
Another reported issue: an error is triggered when the response body (a JSON string) is up to 100K bytes.
packet is small.
@xiaolajiyhy For now you can see if this solution works for you https://github.com/apache/apisix/issues/10069#issuecomment-1687405686
send_chunk
@Guohao1020 This solution just overrides the original upstream response with request body. Was that your intended use case? So basically you solved the issue by changing the upstream response?
In the Java plug-in, request.getbody () is not the request body, but the upstream response body.
If the ext-plugin-post-resp plug-in is enabled, the plug-in must explicitly call the response.setbody (request.getbody ()) method. Even if the plug-in callback method does nothing, it must call the response.setbody (request.getbody ()) method.
Of course, if not set, the plug-in will also return an upstream response to the Apisix gateway, but the request response body will be truncated.
My solution is that the request response body of the plug-in must be set when the plug-in does not do anything. If the method is not manually overridden, the request response body is truncated.
@Revolyssup
