DSS boxcarring 跳过操作
DSS boxcarring skipping operation
我将 DSS 3.5.0 与 PostgreSQL 一起使用,请求框中的一组操作无法以非常特殊的方式运行。我在同一个项目中成功地使用了包含数千个操作的请求框,包括与失败的操作非常相似的操作。其中一个大型请求框失败了,在花了一些时间寻找导致问题的操作之后,我们能够将其减少到一组五个操作。
问题
查看 PostgreSQL 日志,其中一个操作发出的查询未执行,因为它从未到达数据库。
我将调用操作 O1
、O2
、O3
、O4
和 O5
及其查询 Q1
、Q2
、Q3
、Q4
和 Q5
。处理请求并检查生成的数据库日志,我们最终得到:
- 请求框包含
O1
-O2
-O3
-O4
-O5
:数据库执行Q1
-Q2
-Q3
-Q5
- 请求框包含
O1
-O2
-O4
-O5
:数据库执行Q1
-Q2
-Q4
-Q5
- 请求框包含
O1
-O2
-O3
-O4
:数据库执行Q1
-Q2
-Q3
-Q4
- 请求框包含
O1
-O2
-O3
-O4
-O4
-O5
:数据库执行Q1
-Q2
-Q3
-Q5
所以,它看起来很奇怪,而且似乎没有遵循清晰可辨的模式。
如果单独发送到 DSS,或在两个不同的请求框中,所有操作都会正确执行。操作的确切性质似乎与问题没有直接联系,因为在其他场景中无数次使用相同的操作。查询不是特别长或复杂。
- 操作一:更新tableA中的一条记录
- 操作2:从tableB
删除一条记录
- 操作3:在tableB中插入一条记录
- 操作4:在tableA中插入一条记录
- 操作5:在tableB中插入一条记录(同操作3)
错误和日志
PostgreSQL 为操作 5 发出的实际错误信息是
ERROR: null value in column "element_id" violates not-null constraint
这是预期的,因为操作 4(消失的那个)插入了一个值,该值稍后用于解析操作 5 的 element_id
。
PostgreSQL 日志报告:
LOG: execute <unnamed>: BEGIN
LOG: execute <unnamed>: UPDATE public.project_element SET element_uuid=,location_id=,from_revit=,name=,type=,model=NULLIF(,0),parent_element=(SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.PROJECT_ID = AND (PE.ELEMENT_ID = OR (PE.ELEMENT_UUID = AND PE.ELEMENT_UUID IS NOT NULL))) ,left_border=,right_border= WHERE element_id=
DETAIL: parameters: = '(element-uuid)', = '85', = '1', = '(some-text)', = '3', = '0', = '22', = NULL, = '(parent-uuid)', = NULL, = NULL, = '9983'
LOG: execute <unnamed>: DELETE FROM ELEMENT_PROPERTY WHERE ELEMENT_ID = (SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.ELEMENT_ID = AND PE.PROJECT_ID = ) AND NAME =
DETAIL: parameters: = '9983', = '22', = 'num_ports'
LOG: execute <unnamed>: INSERT INTO public.element_property(name,value,type,element_id) VALUES(,,,(^M SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.PROJECT_ID = AND (PE.ELEMENT_ID = OR (PE.ELEMENT_UUID = AND PE.ELEMENT_UUID IS NOT NULL))))
DETAIL: parameters: = 'num_ports', = '48', = '0', = '22', = NULL, = '(element-uuid)'
LOG: execute <unnamed>: INSERT INTO public.element_property(name,value,type,element_id) VALUES(,,,(SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.PROJECT_ID = AND (PE.ELEMENT_ID = OR (PE.ELEMENT_UUID = AND PE.ELEMENT_UUID IS NOT NULL))))
DETAIL: parameters: = 'port_num', = '6', = '0', = '22', = NULL, = '(other-uuid)'
ERROR: null value in column "element_id" violates not-null constraint
DETAIL: Failing row contains (port_num, 6, 0, null).
STATEMENT: INSERT INTO public.element_property(name,value,type,element_id) VALUES(,,,(SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.PROJECT_ID = AND (PE.ELEMENT_ID = OR (PE.ELEMENT_UUID = AND PE.ELEMENT_UUID IS NOT NULL))))
LOG: execute S_2: BEGIN
LOG: execute S_1: ROLLBACK
DSS 日志启动异常,但我不确定它是否真的与此问题有关。以下日志从请求框开始到它第一次抱怨从 PostgreSQL 返回的错误消息。之后DSS多次投诉
DEBUG - {org.apache.axis2.transport.http.AxisServlet}
java.lang.NullPointerException
at javax.servlet.GenericServlet.getServletContext(GenericServlet.java:123)
at org.apache.axis2.transport.http.AxisServlet.createMessageContext(AxisServlet.java:715)
at org.apache.axis2.transport.http.AxisServlet$RestRequestProcessor.<init>(AxisServlet.java:819)
at org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:227)
at org.wso2.carbon.core.transports.CarbonServlet.doPost(CarbonServlet.java:231)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:646)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61)
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128)
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at org.wso2.carbon.tomcat.ext.servlet.DelegationServlet.service(DelegationServlet.java:68)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.wso2.carbon.ui.filters.CSRFPreventionFilter.doFilter(CSRFPreventionFilter.java:88)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.wso2.carbon.ui.filters.CRLFPreventionFilter.doFilter(CRLFPreventionFilter.java:59)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.wso2.carbon.tomcat.ext.filter.CharacterSetFilter.doFilter(CharacterSetFilter.java:61)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.wso2.carbon.tomcat.ext.valves.CompositeValve.continueInvocation(CompositeValve.java:99)
at org.wso2.carbon.tomcat.ext.valves.CarbonTomcatValve.invoke(CarbonTomcatValve.java:47)
at org.wso2.carbon.webapp.mgt.TenantLazyLoaderValve.invoke(TenantLazyLoaderValve.java:57)
at org.wso2.carbon.tomcat.ext.valves.TomcatValveContainer.invokeValves(TomcatValveContainer.java:47)
at org.wso2.carbon.tomcat.ext.valves.CompositeValve.invoke(CompositeValve.java:62)
at org.wso2.carbon.tomcat.ext.valves.CarbonStuckThreadDetectionValve.invoke(CarbonStuckThreadDetectionValve.java:159)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
at org.wso2.carbon.tomcat.ext.valves.CarbonContextCreatorValve.invoke(CarbonContextCreatorValve.java:57)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1074)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1739)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1698)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:744)
DEBUG - Input contentType (application/json) {org.apache.axis2.builder.BuilderUtil}
DEBUG - CharSetEncoding defaulted (UTF-8) {org.apache.axis2.builder.BuilderUtil}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Checking for Service using target endpoint address : /services/iims {org.apache.axis2.dispatchers.RequestURIBasedServiceDispatcher}
DEBUG - org.apache.axis2.i18n.resource::handleGetObject(servicefound) {org.apache.axis2.i18n.ProjectResourceBundle}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Found AxisService : iims {org.apache.axis2.engine.AbstractDispatcher}
DEBUG - Attempt to check for Operation using HTTP Location failed {org.apache.axis2.dispatchers.HTTPLocationBasedDispatcher}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Attempted to check for Operation using target endpoint URI, but the operation fragment was missing {org.apache.axis2.dispatchers.RequestURIBasedOperationDispatcher}
DEBUG - getAction (null) from org.apache.axis2.client.Options@279e70a {org.apache.axis2.client.Options}
DEBUG - SoapAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - createSOAPEnvelope using Builder (class org.apache.axis2.json.JSONOMBuilder) selected from type (application/json) {org.apache.axis2.transport.TransportUtils}
DEBUG - getAction (null) from org.apache.axis2.client.Options@279e70a {org.apache.axis2.client.Options}
DEBUG - SoapAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Checking for Operation using Action : null {org.apache.axis2.dispatchers.ActionBasedOperationDispatcher}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Attempted to check for Operation using target endpoint URI, but the operation fragment was missing {org.apache.axis2.dispatchers.RequestURIBasedOperationDispatcher}
DEBUG - Axis operation is null {org.apache.axis2.json.gson.JSONMessageHandler}
DEBUG - No headers present corresponding to http://www.w3.org/2005/08/addressing {org.apache.axis2.handlers.addressing.AddressingInHandler}
DEBUG - No headers present corresponding to http://schemas.xmlsoap.org/ws/2004/08/addressing {org.apache.axis2.handlers.addressing.AddressingInHandler}
DEBUG - getAction (null) from org.apache.axis2.client.Options@279e70a {org.apache.axis2.client.Options}
DEBUG - SoapAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Checking for Operation using Action : null {org.apache.axis2.dispatchers.ActionBasedOperationDispatcher}
DEBUG - getAction (null) from org.apache.axis2.client.Options@279e70a {org.apache.axis2.client.Options}
DEBUG - SoapAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Checking for Operation using Action : null {org.apache.axis2.dispatchers.ActionBasedOperationDispatcher}
DEBUG - Get operation for request_box {org.apache.axis2.description.AxisService}
DEBUG - Found axis operation: org.apache.axis2.description.InOutAxisOperation@682d0c2c {org.apache.axis2.description.AxisService}
DEBUG - org.apache.axis2.i18n.resource::handleGetObject(operationfound) {org.apache.axis2.i18n.ProjectResourceBundle}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Found AxisOperation : request_box {org.apache.axis2.engine.AbstractDispatcher}
DEBUG - getAddressingRequirementParemeterValue: value: 'null' {org.apache.axis2.addressing.AddressingHelper}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] isReplyRedirected: ReplyTo is null. Returning false {org.apache.axis2.addressing.AddressingHelper}
DEBUG - getAction (null) from org.apache.axis2.client.Options@112f42cb {org.apache.axis2.client.Options}
DEBUG - Old WSAAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - New WSAAction is (urn:request_boxResponse) {org.apache.axis2.context.MessageContext}
DEBUG - setAction Old action is (null) {org.apache.axis2.client.Options}
DEBUG - setAction New action is (urn:request_boxResponse) {org.apache.axis2.client.Options}
DEBUG - messageID is null. {org.apache.axis2.context.ConfigurationContext}
DEBUG - forceExpand: changing prefix from to {org.apache.axiom.om.impl.llom.OMSourcedElementImpl}
DEBUG - DXXATransactionManager.begin() {org.wso2.carbon.dataservices.core.description.xa.DSSXATransactionManager}
DEBUG - Creating data source connection {org.wso2.carbon.dataservices.core.description.config.SQLConfig}
ERROR - ERROR: null value in column "element_id" violates not-null constraint_ Detalhe: Failing row contains (port_num, 6, 0, null). (Sanitized) {org.wso2.carbon.dataservices.core.description.query.SQLQuery}
org.postgresql.util.PSQLException: ERROR: null value in column "element_id" violates not-null constraint
执行
这是实际失败的请求框(替换了一些字段内容以减少噪音):
{
"request_box":{
"update_project_element_operation":{
"name":"(some-text)",
"element_id":9983,
"element_uuid":"(element-uuid)",
"from_revit":1,
"project_id":22,
"parent_element_uuid":"(parent-uuid)",
"type":3,
"location_id":85,
"model":0
},
"delete_element_property_operation":{
"name":"num_ports",
"element_id":9983,
"project_id":22
},
"insert_element_property_operation":{
"project_id":22,
"element_uuid":"(element-uuid)",
"name":"num_ports",
"value":"48"
},
"insert_project_element_operation":{
"name":"(this operation disappears)",
"element_id":0,
"element_uuid":"(other-uuid)",
"from_revit":1,
"project_id":22,
"parent_element_uuid":"(element-uuid)",
"type":10,
"location_id":85,
"model":0
},
"insert_element_property_operation":{
"project_id":22,
"element_uuid":"(other-uuid)",
"name":"port_num",
"value":"6"
}
}
}
如有必要,我可以提供详细的table、查询和操作定义。以前使用过所有操作,如果单独发出或在两个不同的请求框中,它们中的每一个都有效。这似乎是一个与 DSS boxcarring 直接相关的问题。
有什么想法吗?
经过几周的调查,包括直接联系 WSO2 支持,我们得出结论,这个异常问题是由 DSS 内部的 JSON 到 XML 转换引起的。这可能与以下事实有关:JSON 格式的请求框表示可以包含 non-unique 名称(根据 RFC 7159,这种情况下的行为是不可预测的 implementation-defined)。应该注意的是,我们还使用了一个包含数千个相同名称重复的请求框,没有任何明显的问题,因此这并不是所有 non-unique 个名称未被正确处理的直接结果。
当我们在XML中尝试相同的请求框时,所有操作都正确执行。为了避免更改应用程序,我们听从了 WSO2 的建议,让 ESB 将 application-generated JSON 转换为 XML。初步测试表明,在这种情况下 XML 已正确生成,但是我们决定稍微调整 JSON 生成器以发出操作对象数组而不是包含具有 non-unique 名称的成员的对象, 以避免未定义的行为和 JSON 解析中出现新的、不可预测的问题的可能性。
WSO2 已经意识到这个问题,它可能会或可能不会被即将发布的 DSS 修复。在此之前,避免请求框意外的更安全方法似乎是在使用请求框向 DSS 发送交易时使用 XML 而不是 JSON。
我将 DSS 3.5.0 与 PostgreSQL 一起使用,请求框中的一组操作无法以非常特殊的方式运行。我在同一个项目中成功地使用了包含数千个操作的请求框,包括与失败的操作非常相似的操作。其中一个大型请求框失败了,在花了一些时间寻找导致问题的操作之后,我们能够将其减少到一组五个操作。
问题
查看 PostgreSQL 日志,其中一个操作发出的查询未执行,因为它从未到达数据库。
我将调用操作 O1
、O2
、O3
、O4
和 O5
及其查询 Q1
、Q2
、Q3
、Q4
和 Q5
。处理请求并检查生成的数据库日志,我们最终得到:
- 请求框包含
O1
-O2
-O3
-O4
-O5
:数据库执行Q1
-Q2
-Q3
-Q5
- 请求框包含
O1
-O2
-O4
-O5
:数据库执行Q1
-Q2
-Q4
-Q5
- 请求框包含
O1
-O2
-O3
-O4
:数据库执行Q1
-Q2
-Q3
-Q4
- 请求框包含
O1
-O2
-O3
-O4
-O4
-O5
:数据库执行Q1
-Q2
-Q3
-Q5
所以,它看起来很奇怪,而且似乎没有遵循清晰可辨的模式。
如果单独发送到 DSS,或在两个不同的请求框中,所有操作都会正确执行。操作的确切性质似乎与问题没有直接联系,因为在其他场景中无数次使用相同的操作。查询不是特别长或复杂。
- 操作一:更新tableA中的一条记录
- 操作2:从tableB 删除一条记录
- 操作3:在tableB中插入一条记录
- 操作4:在tableA中插入一条记录
- 操作5:在tableB中插入一条记录(同操作3)
错误和日志
PostgreSQL 为操作 5 发出的实际错误信息是
ERROR: null value in column "element_id" violates not-null constraint
这是预期的,因为操作 4(消失的那个)插入了一个值,该值稍后用于解析操作 5 的 element_id
。
PostgreSQL 日志报告:
LOG: execute <unnamed>: BEGIN
LOG: execute <unnamed>: UPDATE public.project_element SET element_uuid=,location_id=,from_revit=,name=,type=,model=NULLIF(,0),parent_element=(SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.PROJECT_ID = AND (PE.ELEMENT_ID = OR (PE.ELEMENT_UUID = AND PE.ELEMENT_UUID IS NOT NULL))) ,left_border=,right_border= WHERE element_id=
DETAIL: parameters: = '(element-uuid)', = '85', = '1', = '(some-text)', = '3', = '0', = '22', = NULL, = '(parent-uuid)', = NULL, = NULL, = '9983'
LOG: execute <unnamed>: DELETE FROM ELEMENT_PROPERTY WHERE ELEMENT_ID = (SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.ELEMENT_ID = AND PE.PROJECT_ID = ) AND NAME =
DETAIL: parameters: = '9983', = '22', = 'num_ports'
LOG: execute <unnamed>: INSERT INTO public.element_property(name,value,type,element_id) VALUES(,,,(^M SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.PROJECT_ID = AND (PE.ELEMENT_ID = OR (PE.ELEMENT_UUID = AND PE.ELEMENT_UUID IS NOT NULL))))
DETAIL: parameters: = 'num_ports', = '48', = '0', = '22', = NULL, = '(element-uuid)'
LOG: execute <unnamed>: INSERT INTO public.element_property(name,value,type,element_id) VALUES(,,,(SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.PROJECT_ID = AND (PE.ELEMENT_ID = OR (PE.ELEMENT_UUID = AND PE.ELEMENT_UUID IS NOT NULL))))
DETAIL: parameters: = 'port_num', = '6', = '0', = '22', = NULL, = '(other-uuid)'
ERROR: null value in column "element_id" violates not-null constraint
DETAIL: Failing row contains (port_num, 6, 0, null).
STATEMENT: INSERT INTO public.element_property(name,value,type,element_id) VALUES(,,,(SELECT PE.ELEMENT_ID FROM PROJECT_ELEMENT PE WHERE PE.PROJECT_ID = AND (PE.ELEMENT_ID = OR (PE.ELEMENT_UUID = AND PE.ELEMENT_UUID IS NOT NULL))))
LOG: execute S_2: BEGIN
LOG: execute S_1: ROLLBACK
DSS 日志启动异常,但我不确定它是否真的与此问题有关。以下日志从请求框开始到它第一次抱怨从 PostgreSQL 返回的错误消息。之后DSS多次投诉
DEBUG - {org.apache.axis2.transport.http.AxisServlet}
java.lang.NullPointerException
at javax.servlet.GenericServlet.getServletContext(GenericServlet.java:123)
at org.apache.axis2.transport.http.AxisServlet.createMessageContext(AxisServlet.java:715)
at org.apache.axis2.transport.http.AxisServlet$RestRequestProcessor.<init>(AxisServlet.java:819)
at org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:227)
at org.wso2.carbon.core.transports.CarbonServlet.doPost(CarbonServlet.java:231)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:646)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61)
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128)
at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:68)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at org.wso2.carbon.tomcat.ext.servlet.DelegationServlet.service(DelegationServlet.java:68)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.wso2.carbon.ui.filters.CSRFPreventionFilter.doFilter(CSRFPreventionFilter.java:88)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.wso2.carbon.ui.filters.CRLFPreventionFilter.doFilter(CRLFPreventionFilter.java:59)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.wso2.carbon.tomcat.ext.filter.CharacterSetFilter.doFilter(CharacterSetFilter.java:61)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.wso2.carbon.tomcat.ext.valves.CompositeValve.continueInvocation(CompositeValve.java:99)
at org.wso2.carbon.tomcat.ext.valves.CarbonTomcatValve.invoke(CarbonTomcatValve.java:47)
at org.wso2.carbon.webapp.mgt.TenantLazyLoaderValve.invoke(TenantLazyLoaderValve.java:57)
at org.wso2.carbon.tomcat.ext.valves.TomcatValveContainer.invokeValves(TomcatValveContainer.java:47)
at org.wso2.carbon.tomcat.ext.valves.CompositeValve.invoke(CompositeValve.java:62)
at org.wso2.carbon.tomcat.ext.valves.CarbonStuckThreadDetectionValve.invoke(CarbonStuckThreadDetectionValve.java:159)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
at org.wso2.carbon.tomcat.ext.valves.CarbonContextCreatorValve.invoke(CarbonContextCreatorValve.java:57)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1074)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1739)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1698)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:744)
DEBUG - Input contentType (application/json) {org.apache.axis2.builder.BuilderUtil}
DEBUG - CharSetEncoding defaulted (UTF-8) {org.apache.axis2.builder.BuilderUtil}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Checking for Service using target endpoint address : /services/iims {org.apache.axis2.dispatchers.RequestURIBasedServiceDispatcher}
DEBUG - org.apache.axis2.i18n.resource::handleGetObject(servicefound) {org.apache.axis2.i18n.ProjectResourceBundle}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Found AxisService : iims {org.apache.axis2.engine.AbstractDispatcher}
DEBUG - Attempt to check for Operation using HTTP Location failed {org.apache.axis2.dispatchers.HTTPLocationBasedDispatcher}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Attempted to check for Operation using target endpoint URI, but the operation fragment was missing {org.apache.axis2.dispatchers.RequestURIBasedOperationDispatcher}
DEBUG - getAction (null) from org.apache.axis2.client.Options@279e70a {org.apache.axis2.client.Options}
DEBUG - SoapAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - createSOAPEnvelope using Builder (class org.apache.axis2.json.JSONOMBuilder) selected from type (application/json) {org.apache.axis2.transport.TransportUtils}
DEBUG - getAction (null) from org.apache.axis2.client.Options@279e70a {org.apache.axis2.client.Options}
DEBUG - SoapAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Checking for Operation using Action : null {org.apache.axis2.dispatchers.ActionBasedOperationDispatcher}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Attempted to check for Operation using target endpoint URI, but the operation fragment was missing {org.apache.axis2.dispatchers.RequestURIBasedOperationDispatcher}
DEBUG - Axis operation is null {org.apache.axis2.json.gson.JSONMessageHandler}
DEBUG - No headers present corresponding to http://www.w3.org/2005/08/addressing {org.apache.axis2.handlers.addressing.AddressingInHandler}
DEBUG - No headers present corresponding to http://schemas.xmlsoap.org/ws/2004/08/addressing {org.apache.axis2.handlers.addressing.AddressingInHandler}
DEBUG - getAction (null) from org.apache.axis2.client.Options@279e70a {org.apache.axis2.client.Options}
DEBUG - SoapAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Checking for Operation using Action : null {org.apache.axis2.dispatchers.ActionBasedOperationDispatcher}
DEBUG - getAction (null) from org.apache.axis2.client.Options@279e70a {org.apache.axis2.client.Options}
DEBUG - SoapAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Checking for Operation using Action : null {org.apache.axis2.dispatchers.ActionBasedOperationDispatcher}
DEBUG - Get operation for request_box {org.apache.axis2.description.AxisService}
DEBUG - Found axis operation: org.apache.axis2.description.InOutAxisOperation@682d0c2c {org.apache.axis2.description.AxisService}
DEBUG - org.apache.axis2.i18n.resource::handleGetObject(operationfound) {org.apache.axis2.i18n.ProjectResourceBundle}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] Found AxisOperation : request_box {org.apache.axis2.engine.AbstractDispatcher}
DEBUG - getAddressingRequirementParemeterValue: value: 'null' {org.apache.axis2.addressing.AddressingHelper}
DEBUG - [MessageContext: logID=f9462531f982d008b3e2aacd88bfd07f4a7e4905c354170e] isReplyRedirected: ReplyTo is null. Returning false {org.apache.axis2.addressing.AddressingHelper}
DEBUG - getAction (null) from org.apache.axis2.client.Options@112f42cb {org.apache.axis2.client.Options}
DEBUG - Old WSAAction is (null) {org.apache.axis2.context.MessageContext}
DEBUG - New WSAAction is (urn:request_boxResponse) {org.apache.axis2.context.MessageContext}
DEBUG - setAction Old action is (null) {org.apache.axis2.client.Options}
DEBUG - setAction New action is (urn:request_boxResponse) {org.apache.axis2.client.Options}
DEBUG - messageID is null. {org.apache.axis2.context.ConfigurationContext}
DEBUG - forceExpand: changing prefix from to {org.apache.axiom.om.impl.llom.OMSourcedElementImpl}
DEBUG - DXXATransactionManager.begin() {org.wso2.carbon.dataservices.core.description.xa.DSSXATransactionManager}
DEBUG - Creating data source connection {org.wso2.carbon.dataservices.core.description.config.SQLConfig}
ERROR - ERROR: null value in column "element_id" violates not-null constraint_ Detalhe: Failing row contains (port_num, 6, 0, null). (Sanitized) {org.wso2.carbon.dataservices.core.description.query.SQLQuery}
org.postgresql.util.PSQLException: ERROR: null value in column "element_id" violates not-null constraint
执行
这是实际失败的请求框(替换了一些字段内容以减少噪音):
{
"request_box":{
"update_project_element_operation":{
"name":"(some-text)",
"element_id":9983,
"element_uuid":"(element-uuid)",
"from_revit":1,
"project_id":22,
"parent_element_uuid":"(parent-uuid)",
"type":3,
"location_id":85,
"model":0
},
"delete_element_property_operation":{
"name":"num_ports",
"element_id":9983,
"project_id":22
},
"insert_element_property_operation":{
"project_id":22,
"element_uuid":"(element-uuid)",
"name":"num_ports",
"value":"48"
},
"insert_project_element_operation":{
"name":"(this operation disappears)",
"element_id":0,
"element_uuid":"(other-uuid)",
"from_revit":1,
"project_id":22,
"parent_element_uuid":"(element-uuid)",
"type":10,
"location_id":85,
"model":0
},
"insert_element_property_operation":{
"project_id":22,
"element_uuid":"(other-uuid)",
"name":"port_num",
"value":"6"
}
}
}
如有必要,我可以提供详细的table、查询和操作定义。以前使用过所有操作,如果单独发出或在两个不同的请求框中,它们中的每一个都有效。这似乎是一个与 DSS boxcarring 直接相关的问题。
有什么想法吗?
经过几周的调查,包括直接联系 WSO2 支持,我们得出结论,这个异常问题是由 DSS 内部的 JSON 到 XML 转换引起的。这可能与以下事实有关:JSON 格式的请求框表示可以包含 non-unique 名称(根据 RFC 7159,这种情况下的行为是不可预测的 implementation-defined)。应该注意的是,我们还使用了一个包含数千个相同名称重复的请求框,没有任何明显的问题,因此这并不是所有 non-unique 个名称未被正确处理的直接结果。
当我们在XML中尝试相同的请求框时,所有操作都正确执行。为了避免更改应用程序,我们听从了 WSO2 的建议,让 ESB 将 application-generated JSON 转换为 XML。初步测试表明,在这种情况下 XML 已正确生成,但是我们决定稍微调整 JSON 生成器以发出操作对象数组而不是包含具有 non-unique 名称的成员的对象, 以避免未定义的行为和 JSON 解析中出现新的、不可预测的问题的可能性。
WSO2 已经意识到这个问题,它可能会或可能不会被即将发布的 DSS 修复。在此之前,避免请求框意外的更安全方法似乎是在使用请求框向 DSS 发送交易时使用 XML 而不是 JSON。