测试验证功能时在日志中发现的，偶现，完整日志：
[2023-07-04 20:13:36.817] INFO [kfcs-clear,017358f68a1346ba,02274a355cc34e01,11ec1f71fe486df6] 13366 — [core-cf-thread-3] com.szkingdom.koca.jdbc.JdbcHelper 160: 执行结果 = 1，执行耗时 : [ 5 ms ]
[2023-07-04 20:13:36.817] INFO [kfcs-clear,017358f68a1346ba,02274a355cc34e01,11ec1f71fe486df6] 13366 — [core-cf-thread-3] c.s.k.a.c.s.impl.BexLogServiceImpl 117: Bex接口queryPendingBill调用日志记录成功
[2023-07-04 20:13:50.091] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:13:50.676] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-Acceptor] c.s.kwas.logging.log.DirectJDKLog 163: Counting up[http-nio-39141-Acceptor] latch=2
[2023-07-04 20:13:50.679] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Processing socket [com.szkingdom.kwas.web.util.net.NioChannel@78b7b141:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43782]] with status [OPEN_READ]
[2023-07-04 20:13:50.679] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Found processor [null] for socket [com.szkingdom.kwas.web.util.net.NioChannel@78b7b141:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43782]]
[2023-07-04 20:13:50.679] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Popped processor [com.szkingdom.kwas.kconnector.http11.Http11Processor@374d4a1c] from cache
[2023-07-04 20:13:50.679] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Before fill(): parsingHeader: [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position(): [0], byteBuffer.limit(): [0], end: [1526]
[2023-07-04 20:13:50.679] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Socket: [com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper@3dff8a23:com.szkingdom.kwas.web.util.net.NioChannel@78b7b141:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43782]], Read from buffer: [0]
[2023-07-04 20:13:50.680] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Socket: [com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper@3dff8a23:com.szkingdom.kwas.web.util.net.NioChannel@78b7b141:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43782]], Read direct from socket: [812]
[2023-07-04 20:13:50.680] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Received [POST /api/unAutoCoupling HTTP/1.1
Content-Type: application/json
koca-request-bytes: 19
koca-source-service: kfcs-auto
trustedprincipal: eyJ1c2VyTm8iOiIzMjEiLCJ1c2VyQ29kZSI6Inp3aiIsInVzZXJOYW1lIjoi5ZGo5paH5p2wIiwib3RoZXJzIjp7InB3ZEV4cGlyZWRGbGFnIjoiMSIsInN5c0RhdGUiOiIyMDIzLTA3LTA0IiwibmV0bm8iOiIwMDAxIiwiaXNGaXJzdExvZ2luIjoiMCIsInB3ZEV4cGlyZVJlbWluZCI6IjAiLCJ0ZW5hbnRpZCI6IjAwMDEiLCJvcmdpZCI6IjAwMDEiLCJsb2dpbk5hbWUiOiIzMjEifSwiZW5hYmxlZCI6ZmFsc2UsImFjY291bnROb25FeHBpcmVkIjpmYWxzZSwiYWNjb3VudE5vbkxvY2tlZCI6ZmFsc2UsImNyZWRlbnRpYWxzTm9uRXhwaXJlZCI6ZmFsc2V9
X-B3-TraceId: 35a1a4d43a865319
X-B3-SpanId: 401542ec88c19db7
X-B3-ParentSpanId: 13df8427be3198ce
X-B3-Sampled: 1
Accept: /
User-Agent: Java/1.8.0_281
Host: 10.202.41.57:39141
Connection: keep-alive
Content-Length: 19
{“tenantid”:“0001”}]
[2023-07-04 20:13:50.680] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Security checking request POST /api/unAutoCoupling
[2023-07-04 20:13:50.681] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: No applicable constraints defined
[2023-07-04 20:13:50.681] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Not subject to any constraint
[2023-07-04 20:13:50.681] INFO [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.k.a.c.filter.CommonParamsFilter 70: CommonParamContext is null
[2023-07-04 20:13:50.683] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.k.s.interceptor.LanguageInterceptor 34: can not find Lang in request header.set locale：zh_CN
[2023-07-04 20:13:50.684] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.k.s.interceptor.LanguageInterceptor 39: set Lang: zh_CN
[2023-07-04 20:13:50.684] INFO [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.koca.bex.controller.ApiController 69: request data {“tenantid”:“0001”}
[2023-07-04 20:13:50.685] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] s.k.a.w.s.i.WebAuthContextHolderStrategy 32: WebAuthContextHolderStrategy getPrincipal from auth web ThreadLocal
[2023-07-04 20:13:50.686] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 133: *bex commonParam start
[2023-07-04 20:13:50.686] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_clienttype=null
[2023-07-04 20:13:50.686] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_userid=321
[2023-07-04 20:13:50.687] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: source=null
[2023-07-04 20:13:50.687] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_funcid=unAutoCoupling
[2023-07-04 20:13:50.687] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: userid=321
[2023-07-04 20:13:50.687] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: uuid=null
[2023-07-04 20:13:50.687] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: mac=null
[2023-07-04 20:13:50.688] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: hostname=10.202.41.57
[2023-07-04 20:13:50.688] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: tenantid=0001
[2023-07-04 20:13:50.688] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: action=null
[2023-07-04 20:13:50.688] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: checkstatus=null
[2023-07-04 20:13:50.688] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_sysid=null
[2023-07-04 20:13:50.688] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_menuid=null
[2023-07-04 20:13:50.689] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: netno=0001
[2023-07-04 20:13:50.689] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: ip=null
[2023-07-04 20:13:50.689] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_orgid=null
[2023-07-04 20:13:50.689] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_clientid=null
[2023-07-04 20:13:50.689] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: acceptmethod=null
[2023-07-04 20:13:50.689] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: funcid=unAutoCoupling
[2023-07-04 20:13:50.690] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: orgid=0001
[2023-07-04 20:13:50.690] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_username=周文杰
[2023-07-04 20:13:50.690] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_action=null
[2023-07-04 20:13:50.690] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: checksno=null
[2023-07-04 20:13:50.690] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: imei=null
[2023-07-04 20:13:50.690] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: menuid=null
[2023-07-04 20:13:50.691] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_stationaddr=10.202.41.57
[2023-07-04 20:13:50.691] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: checkflag=null
[2023-07-04 20:13:50.691] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: username=周文杰
[2023-07-04 20:13:50.691] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 134: g_userway=null
[2023-07-04 20:13:50.691] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] .k.a.c.s.i.DefaultCommonParamServiceImpl 135: *bex commonParam end
[2023-07-04 20:13:50.692] INFO [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.k.a.c.c.p.a.ConfirmAopConfiguration 59: 请求公参:{g_clienttype=null, g_userid=321, source=null, g_funcid=unAutoCoupling, userid=321, uuid=null, mac=null, hostname=10.202.41.57, tenantid=0001, action=null, checkstatus=null, g_sysid=null, g_menuid=null, netno=0001, ip=null, g_orgid=null, g_clientid=null, acceptmethod=null, funcid=unAutoCoupling, orgid=0001, g_username=周文杰, g_action=null, checksno=null, imei=null, menuid=null, g_stationaddr=10.202.41.57, checkflag=null, username=周文杰, g_userway=null}
[2023-07-04 20:13:50.692] INFO [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.k.c.d.base.SysWorkcalendarBaseData 196: 进入查询单条
[2023-07-04 20:13:50.692] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.k.a.cache.core.CacheVersionManager 147: key:sys_data_config_cache:1 incrementRelation is 1
[2023-07-04 20:13:50.693] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] org.mybatis.logging.Logger 49: Creating a new SqlSession
[2023-07-04 20:13:50.693] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] org.mybatis.logging.Logger 49: SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2e7be688] was not registered for synchronization because synchronization is not active
[2023-07-04 20:13:50.694] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] org.mybatis.logging.Logger 49: JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@73f853bc] will not be managed by Spring
[2023-07-04 20:13:50.694] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] o.a.ibatis.logging.jdbc.BaseJdbcLogger 137: ==> Preparing: select phydate, market, work_date_flag from sys_workcalendar where phydate=? and market=?
[2023-07-04 20:13:50.695] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] o.a.ibatis.logging.jdbc.BaseJdbcLogger 137: ==> Parameters: 20230704(Integer), 0(String)
[2023-07-04 20:13:50.697] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] o.a.ibatis.logging.jdbc.BaseJdbcLogger 137: <== Total: 1
[2023-07-04 20:13:50.697] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] org.mybatis.logging.Logger 49: Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@2e7be688]
[2023-07-04 20:13:50.698] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] org.mybatis.logging.Logger 49: Creating a new SqlSession
[2023-07-04 20:13:50.698] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] org.mybatis.logging.Logger 49: SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@56065269] was not registered for synchronization because synchronization is not active
[2023-07-04 20:13:50.699] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] org.mybatis.logging.Logger 49: JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@73f853bc] will not be managed by Spring
[2023-07-04 20:13:50.699] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] o.a.ibatis.logging.jdbc.BaseJdbcLogger 137: ==> Preparing: select serial_no, become_due_date, cancellation_date, pay_date, status, pending_type, remark, tenantid, createby, updateby, updatedate, createdate, dataid from fcs_pendingbill where tenantid = ? and status = ? and become_due_date is not null and become_due_date != ‘’ and become_due_date <= ?
[2023-07-04 20:13:50.700] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] o.a.ibatis.logging.jdbc.BaseJdbcLogger 137: ==> Parameters: 0001(String), 1(String), 20230704(String)
[2023-07-04 20:13:50.701] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] o.a.ibatis.logging.jdbc.BaseJdbcLogger 137: <== Total: 0
[2023-07-04 20:13:50.703] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] org.mybatis.logging.Logger 49: Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@56065269]
[2023-07-04 20:13:50.703] INFO [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.k.c.h.p.p.UnAutoCouplingHandler 48: 没有待解挂的挂账数据，无需执行解挂任务！
[2023-07-04 20:13:50.706] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] s.k.a.w.s.i.WebAuthContextHolderStrategy 32: WebAuthContextHolderStrategy getPrincipal from auth web ThreadLocal
[2023-07-04 20:13:50.707] DEBUG [kfcs-clear,35a1a4d43a865319,401542ec88c19db7,13df8427be3198ce] 13366 — [http-nio-39141-exec-10] c.s.koca.bex.controller.ApiController 87: {“code”:“0”,“msg”:“请求处理成功”,“detail”:"",“head”:{}}
[2023-07-04 20:13:50.709] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Before fill(): parsingHeader: [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position(): [0], byteBuffer.limit(): [0], end: [793]
[2023-07-04 20:13:50.709] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Socket: [com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper@3dff8a23:com.szkingdom.kwas.web.util.net.NioChannel@78b7b141:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43782]], Read from buffer: [0]
[2023-07-04 20:13:50.710] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 165: Error parsing HTTP request header
java.io.EOFException: null
at com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1329)
at com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper.read(NioEndpoint.java:1216)
at com.szkingdom.kwas.kconnector.http11.Http11InputBuffer.fill(Http11InputBuffer.java:795)
at com.szkingdom.kwas.kconnector.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:350)
at com.szkingdom.kwas.kconnector.http11.Http11Processor.service(Http11Processor.java:261)
at com.szkingdom.kwas.kconnector.AbstractProcessorLight.process(AbstractProcessorLight.java:55)
at com.szkingdom.kwas.kconnector.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:879)
at com.szkingdom.kwas.web.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1733)
at com.szkingdom.kwas.web.util.net.SocketProcessorBase.run(SocketProcessorBase.java:39)
at com.szkingdom.kwas.web.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1181)
at com.szkingdom.kwas.web.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:649)
at com.szkingdom.kwas.web.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:51)
at java.lang.Thread.run(Thread.java:748)
[2023-07-04 20:13:50.710] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 165: Error state [CLOSE_CONNECTION_NOW] reported while processing request
java.io.EOFException: null
at com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper.fillReadBuffer(NioEndpoint.java:1329)
at com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper.read(NioEndpoint.java:1216)
at com.szkingdom.kwas.kconnector.http11.Http11InputBuffer.fill(Http11InputBuffer.java:795)
at com.szkingdom.kwas.kconnector.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:350)
at com.szkingdom.kwas.kconnector.http11.Http11Processor.service(Http11Processor.java:261)
at com.szkingdom.kwas.kconnector.AbstractProcessorLight.process(AbstractProcessorLight.java:55)
at com.szkingdom.kwas.kconnector.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:879)
at com.szkingdom.kwas.web.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1733)
at com.szkingdom.kwas.web.util.net.SocketProcessorBase.run(SocketProcessorBase.java:39)
at com.szkingdom.kwas.web.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1181)
at com.szkingdom.kwas.web.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:649)
at com.szkingdom.kwas.web.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:51)
at java.lang.Thread.run(Thread.java:748)
[2023-07-04 20:13:50.710] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Socket: [com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper@3dff8a23:com.szkingdom.kwas.web.util.net.NioChannel@78b7b141:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43782]], Status in: [OPEN_READ], State out: [CLOSED]
[2023-07-04 20:13:50.710] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Pushed Processor [com.szkingdom.kwas.kconnector.http11.Http11Processor@374d4a1c]
[2023-07-04 20:13:50.711] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Counting down[http-nio-39141-exec-10] latch=2
[2023-07-04 20:13:50.711] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-10] c.s.kwas.logging.log.DirectJDKLog 163: Calling [com.szkingdom.kwas.web.util.net.NioEndpoint@147fcd33].closeSocket([com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper@3dff8a23:com.szkingdom.kwas.web.util.net.NioChannel@78b7b141:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43782]])
[2023-07-04 20:13:50.716] INFO [kfcs-clear,35a1a4d43a865319,8603dcbbd68efd91,401542ec88c19db7] 13366 — [core-cf-thread-4] com.szkingdom.koca.jdbc.JdbcHelper 155: 执行 sql: INSERT INTO bex_call_log (DATAID, BEX_ID, BEX_NAME, COST_TIME, CALL_DATE
, USER_ID, PARAM_JSON, RESPONSE_JSON, RETURN_CODE, RETURN_MESSAGE
, CLIENT_IP)
VALUES (:dataid, :bexId, :bexName, :costTime, :callDate
, :userId, :paramJson, :responseJson, :returnCode, :returnMessage
, :clientIp)
[2023-07-04 20:13:50.722] INFO [kfcs-clear,35a1a4d43a865319,8603dcbbd68efd91,401542ec88c19db7] 13366 — [core-cf-thread-4] com.szkingdom.koca.jdbc.JdbcHelper 160: 执行结果 = 1，执行耗时 : [ 5 ms ]
[2023-07-04 20:13:50.722] INFO [kfcs-clear,35a1a4d43a865319,8603dcbbd68efd91,401542ec88c19db7] 13366 — [core-cf-thread-4] c.s.k.a.c.s.impl.BexLogServiceImpl 117: Bex接口unAutoCoupling调用日志记录成功
[2023-07-04 20:14:02.470] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-2] c.s.kwas.logging.log.DirectJDKLog 163: Start expire sessions StandardManager at 1688472842470 sessioncount 0
[2023-07-04 20:14:02.471] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-2] c.s.kwas.logging.log.DirectJDKLog 163: End expire sessions StandardManager processingTime 1 expired sessions: 0
[2023-07-04 20:14:19.592] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:14:37.711] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-2] c.s.kwas.logging.log.DirectJDKLog 163: Processing socket [com.szkingdom.kwas.web.util.net.NioChannel@6cbf141f:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43504]] with status [ERROR]
[2023-07-04 20:14:37.711] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-2] c.s.kwas.logging.log.DirectJDKLog 163: Found processor [null] for socket [com.szkingdom.kwas.web.util.net.NioChannel@6cbf141f:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43504]]
[2023-07-04 20:14:37.711] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-2] c.s.kwas.logging.log.DirectJDKLog 163: Counting down[http-nio-39141-exec-2] latch=1
[2023-07-04 20:14:37.711] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-2] c.s.kwas.logging.log.DirectJDKLog 163: Calling [com.szkingdom.kwas.web.util.net.NioEndpoint@147fcd33].closeSocket([com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper@6388d53b:com.szkingdom.kwas.web.util.net.NioChannel@6cbf141f:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:43504]])
[2023-07-04 20:14:49.094] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:15:02.472] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-2] c.s.kwas.logging.log.DirectJDKLog 163: Start expire sessions StandardManager at 1688472902472 sessioncount 0
[2023-07-04 20:15:02.473] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-2] c.s.kwas.logging.log.DirectJDKLog 163: End expire sessions StandardManager processingTime 1 expired sessions: 0
[2023-07-04 20:15:18.595] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:15:48.097] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:16:02.474] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-2] c.s.kwas.logging.log.DirectJDKLog 163: Start expire sessions StandardManager at 1688472962474 sessioncount 0
[2023-07-04 20:16:02.475] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-2] c.s.kwas.logging.log.DirectJDKLog 163: End expire sessions StandardManager processingTime 1 expired sessions: 0
[2023-07-04 20:16:17.598] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:16:47.100] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:17:02.477] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-1] c.s.kwas.logging.log.DirectJDKLog 163: Start expire sessions StandardManager at 1688473022476 sessioncount 0
[2023-07-04 20:17:02.477] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-1] c.s.kwas.logging.log.DirectJDKLog 163: End expire sessions StandardManager processingTime 1 expired sessions: 0
[2023-07-04 20:17:16.602] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:17:33.612] INFO [kfcs-clear,] 13366 — [cale-update-thread] c.s.k.a.i.sequence.DefaultSequence$1 125: idGenerator update time year-month-day:202374
[2023-07-04 20:17:46.104] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:18:02.479] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-2] c.s.kwas.logging.log.DirectJDKLog 163: Start expire sessions StandardManager at 1688473082478 sessioncount 0
[2023-07-04 20:18:02.479] DEBUG [kfcs-clear,] 13366 — [KContainer-utility-2] c.s.kwas.logging.log.DirectJDKLog 163: End expire sessions StandardManager processingTime 1 expired sessions: 0
[2023-07-04 20:18:15.606] INFO [kfcs-clear,] 13366 — [com.alibaba.nacos.client.Worker.longPolling.fixed-10.202.41.57_8848-public] n.c.c.i.ClientWorker$LongPollingRunnable 522: get changedGroupKeys:[]
[2023-07-04 20:18:24.405] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-Acceptor] c.s.kwas.logging.log.DirectJDKLog 163: Counting up[http-nio-39141-Acceptor] latch=1
[2023-07-04 20:18:24.405] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-1] c.s.kwas.logging.log.DirectJDKLog 163: Processing socket [com.szkingdom.kwas.web.util.net.NioChannel@6cbf141f:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:47022]] with status [OPEN_READ]
[2023-07-04 20:18:24.405] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-1] c.s.kwas.logging.log.DirectJDKLog 163: Found processor [null] for socket [com.szkingdom.kwas.web.util.net.NioChannel@6cbf141f:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:47022]]
[2023-07-04 20:18:24.405] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-1] c.s.kwas.logging.log.DirectJDKLog 163: Popped processor [com.szkingdom.kwas.kconnector.http11.Http11Processor@374d4a1c] from cache
[2023-07-04 20:18:24.406] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-1] c.s.kwas.logging.log.DirectJDKLog 163: Before fill(): parsingHeader: [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position(): [0], byteBuffer.limit(): [0], end: [793]
[2023-07-04 20:18:24.406] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-1] c.s.kwas.logging.log.DirectJDKLog 163: Socket: [com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper@75db38c3:com.szkingdom.kwas.web.util.net.NioChannel@6cbf141f:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:47022]], Read from buffer: [0]
[2023-07-04 20:18:24.406] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-1] c.s.kwas.logging.log.DirectJDKLog 163: Socket: [com.szkingdom.kwas.web.util.net.NioEndpoint$NioSocketWrapper@75db38c3:com.szkingdom.kwas.web.util.net.NioChannel@6cbf141f:java.nio.channels.SocketChannel[connected local=/10.202.41.57:39141 remote=/10.202.41.57:47022]], Read direct from socket: [1664]
[2023-07-04 20:18:24.406] DEBUG [kfcs-clear,] 13366 — [http-nio-39141-exec-1] c.s.kwas.logging.log.DirectJDKLog 163: Received [POST /api/queryPendingBill HTTP/1.1
X-Real-IP: 10.50.8.21
X-Forwarded-For: 10.50.8.21,10.202.41.57
Content-Length: 138
Access-Control-Allow-Origin: *
Accept: application/json
Lang: zh-CN
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36
Content-Type: application/json;charset=UTF-8
Origin: http://10.202.41.57:9000
Referer: http://10.202.41.57:9000/
Accept-Encoding: gzip, deflate
Accept-Language: zh-CN,zh;q=0.9
Cookie: JSESSIONID=eaccb374-c983-4fd7-b1df-20151c7bca4c
trustedprincipal: eyJ1c2VyTm8iOiIzMjEiLCJ1c2VyQ29kZSI6Inp3aiIsInVzZXJOYW1lIjoi5ZGo5paH5p2wIiwicGVybWlzc2lvbnMiOlt7ImFwaUNvZGUiOiIxMDAyMDkifSx7ImFwaUNvZGUiOiIxMDAzNDEifSx7ImFwaUNvZGUiOiIxMDAyMTAifSx7ImFwaUNvZGUiOiIxMDAzMTAifSx7ImFwaUNvZGUiOiIxMDAxMDMifSx7ImFwaUNvZGUiOiIxMDAyMTMifV0sIm90aGVycyI6eyJwd2RFeHBpcmVkRmxhZyI6IjEiLCJzeXNEYXRlIjoiMjAyMy0wNy0wNCIsIm5ldG5vIjoiMDAwMSIsImlzRmlyc3RMb2dpbiI6IjAiLCJwd2RFeHBpcmVSZW1pbmQiOiIwIiwidGVuYW50aWQiOiIwMDAxIiwib3JnaWQiOiIwMDAxIiwibG9naW5OYW1lIjoiMzIxIn0sImFjY291bnROb25FeHBpcmVkIjpmYWxzZSwiYWNjb3VudE5vbkxvY2tlZCI6ZmFsc2UsImNyZWRlbnRpYWxzTm9uRXhwaXJlZCI6ZmFsc2UsImVuYWJsZWQiOmZhbHNlfQ==
Forwarded: proto=http;host=“10.202.41.57:9000”;for=“10.202.41.57:58394”
X-Forwarded-Proto: http
X-Forwarded-Prefix: /kfcs-clear
X-Forwarded-Port: 9000
X-Forwarded-Host: 10.202.41.57:9000
X-B3-TraceId: 3fd8e1f029f3e88c
X-B3-SpanId: 2281b3866965b5db
X-B3-ParentSpanId: 3fd8e1f029f3e88c
X-B3-Sampled: 1
host: 10.202.41.57:39141
