Ajax请求发出三十分钟后才到达后台

m0_37105523 2019-10-30 10:23:06

昨天碰见一个很奇怪的问题,用户点了update请求后前台一直没有反应,查看日志发现用户点击按钮的时间大约是10:13,执行update是在10:43分,相差三十分钟。
一周前出现过一次这个问题,当时没注意只当是卡住了,这次再次出现希望能把它根除,
项目是很基本的Spring Structs2 Mybatis项目
请求用的ajax
重复多次
{
用户点击详情
2019-10-29 10:13:15 DEBUG [http-apr-8080-exec-11] - ==> Preparing: select CUS_NO, CUS_EXT_NO, CUS_NAME, CUS_TYPE, GROUP_IO, VAT_NO, BANK_CARD, BANK_NAME, ADDRESS, EMAIL, TELEPHONE, AREA_NO, AREA_NAME, EXPRESS_PROVINCE, EXPRESS_CITY, EXPRESS_AREA, EXPRESS_ADDR, POST_CODE, REC_PERSON, REC_PERSON_TEL, REMARK, CREATE_DATE, UPDATE_DATE, ORG_NO, ORG_NAME, REG_NO, REG_NAME, LST_ORG_NO, LST_ORG_NAME, LST_REG_NO, LST_REG_NAME, REG_DATE, LST_DATE, SHFYBNSR, SHIFOUGX, ts, mdm, open_need, open_type, is_success, custtype from t_cus_info WHERE CUS_NO = ?
2019-10-29 10:13:15 DEBUG [http-apr-8080-exec-11] - ==> Parameters: 0513650(String)
2019-10-29 10:13:15 TRACE [http-apr-8080-exec-11] - <== Columns: CUS_NO, CUS_EXT_NO, CUS_NAME, CUS_TYPE, GROUP_IO, VAT_NO, BANK_CARD, BANK_NAME, ADDRESS, EMAIL, TELEPHONE, AREA_NO, AREA_NAME, EXPRESS_PROVINCE, EXPRESS_CITY, EXPRESS_AREA, EXPRESS_ADDR, POST_CODE, REC_PERSON, REC_PERSON_TEL, REMARK, CREATE_DATE, UPDATE_DATE, ORG_NO, ORG_NAME, REG_NO, REG_NAME, LST_ORG_NO, LST_ORG_NAME, LST_REG_NO, LST_REG_NAME, REG_DATE, LST_DATE, SHFYBNSR, SHIFOUGX, TS, MDM, OPEN_NEED, OPEN_TYPE, IS_SUCCESS, CUSTTYPE
2019-10-29 10:13:15 TRACE [http-apr-8080-exec-11] - <== Row: 0513650, 0513650, ****有限公司, 2, 2, 91520302MA6DM0WL59, 0211001400001061, ****, null, null, 0851-28677717, null, null, null, null, null, ****, null, null, null, null, null, 2019-10-24 00:00:00.0, null, null, null, null, 100000, 本地, 01515927, 0024wgk, null, 20191024, 1, 0, 2019-10-24 14:51:25, null, 1, null, null, 02
2019-10-29 10:13:15 DEBUG [http-apr-8080-exec-11] - <== Total: 1
2019-10-29 10:13:15 INFO [http-apr-8080-exec-11] - SQL:[select CUS_NO, CUS_EXT_NO, CUS_NAME, CUS_TYPE, GROUP_IO, VAT_NO, BANK_CARD, BANK_NAME, ADDRESS, EMAIL, TELEPHONE, AREA_NO, AREA_NAME, EXPRESS_PROVINCE, EXPRESS_CITY, EXPRESS_AREA, EXPRESS_ADDR, POST_CODE, REC_PERSON, REC_PERSON_TEL, REMARK, CREATE_DATE, UPDATE_DATE, ORG_NO, ORG_NAME, REG_NO, REG_NAME, LST_ORG_NO, LST_ORG_NAME, LST_REG_NO, LST_REG_NAME, REG_DATE, LST_DATE, SHFYBNSR, SHIFOUGX, ts, mdm, open_need, open_type, is_success, custtype from t_cus_info WHERE CUS_NO = "0513650"]执行耗时[9ms]
用户点击更新 没有返回
用户关闭界面
}

到达后台请求日志
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-29] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-29] - ==> Parameters: XAID546(String), ****有限公司(String), 2(String), 2(String), ****(String), 1001001001001001(String), ****(String), (String), (String), 0851-28677717(String), (String), (String), null, null, null, ****(String), (String), (String), (String), null, 2019-10-29(Date), 100000(String), 本地(String), 0000(String), 超级管理员(String), 20191029(String), 1(String), 0(String), null, null, 1(String), 2(String), null, null, XAID546(String)
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-23] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-14] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-10] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-5] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-2] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-15] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-29] - <== Updates: 1
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-20] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-21] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
2019-10-29 10:43:31 DEBUG [http-apr-8080-exec-25] - ==> Preparing: update t_cus_info SET CUS_EXT_NO=?, CUS_NAME=?, CUS_TYPE=?, GROUP_IO=?, VAT_NO=?, BANK_CARD=?, BANK_NAME=?, ADDRESS=?, EMAIL=?, TELEPHONE=?, AREA_NO=?, AREA_NAME=?, EXPRESS_PROVINCE=?, EXPRESS_CITY=?, EXPRESS_AREA=?, EXPRESS_ADDR=?, POST_CODE=?, REC_PERSON=?, REC_PERSON_TEL=?, REMARK=?, UPDATE_DATE=?, LST_ORG_NO=?, LST_ORG_NAME=?, LST_REG_NO=?, LST_REG_NAME=?, LST_DATE=?, SHFYBNSR=?, SHIFOUGX=?, TS=?, MDM=?, open_need=?, open_type=?, is_success=?, custtype=? where CUS_NO = ?
....
<>
请求记录
**.***.40.191 - - [29/Oct/2019:10:43:31 +0800] "POST /vat/BuyerInfoActionAjax_updateBuyerInfoAjax.action HTTP/1.1" 200 39
**.***.34.251 - - [29/Oct/2019:10:43:31 +0800] "POST /vat/BuyerInfoActionAjax_updateBuyerInfoAjax.action HTTP/1.1" 200 39
**.***.34.251 - - [29/Oct/2019:10:43:31 +0800] "POST /vat/BuyerInfoActionAjax_updateBuyerInfoAjax.action HTTP/1.1" 200 39
**.***.34.251 - - [29/Oct/2019:10:43:32 +0800] "POST /vat/BuyerInfoActionAjax_updateBuyerInfoAjax.action HTTP/1.1" 200 39
**.***.40.191 - - [29/Oct/2019:10:43:32 +0800] "POST /vat/BuyerInfoActionAjax_updateBuyerInfoAjax.action HTTP/1.1" 200 39
**.***.40.191 - - [29/Oct/2019:10:43:32 +0800] "POST /vat/BuyerInfoActionAjax_updateBuyerInfoAjax.action HTTP/1.1" 200 39
**.***.40.191 - - [29/Oct/2019:10:43:32 +0800] "POST /vat/BuyerInfoActionAjax_updateBuyerInfoAjax.action HTTP/1.1" 200 39
**.***..40.191 - - [29/Oct/2019:10:43:32 +0800] "POST /vat/BuyerInfoActionAjax_updateBuyerInfoAjax.action HTTP/1.1" 200 39
<button type="button" onclick="changeHidden()" style="width: 100px;height: 20px;"></button >
希望大家能帮我下 我自己知识范围是真的不够
...全文
544 21 打赏 收藏 转发到动态 举报
写回复
用AI写文章
21 条回复
切换为时间正序
请发表友善的回复…
发表回复
weixin_43348716 2019-11-23
  • 打赏
  • 举报
回复
线程问题,可能造成线程阻塞
m0_37105523 2019-11-13
  • 打赏
  • 举报
回复
引用 21 楼 lin_tj 的回复:
排除前端请求,自己模拟请求有没有这个问题?
没有 测试两个link之前的库是直连的 所以没这个问题
m0_37105523 2019-11-13
  • 打赏
  • 举报
回复
两周了一直没再出现过 推测是有dblink使用后没关,link之间的两个库的连接被防火墙关闭,但是连接池不知道,insert拿到连接后就锁表了
把使用dblink的语句显示关闭后就没再出现过这个问题 等我抽空弄个linux重现一下试试
但是不知道这个30分钟是咋来的 以前碰到这类似问题的时候只卡住15分钟来着(15分钟来源https://my.oschina.net/mawx/blog/318965)
  • 打赏
  • 举报
回复
引用 8 楼 nayi_224 的回复:
锁表 后台有阻塞写法 报错日志被吞了 30分钟前后的日志不是来自一个请求 客户喝多了 基本上就这些原因,挨个试吧
感觉锁表和日志找错了这两个原因
lin_tj 2019-11-04
  • 打赏
  • 举报
回复
排除前端请求,自己模拟请求有没有这个问题?
AT152S 2019-11-03
  • 打赏
  • 举报
回复
应该是表被锁了吧 update 不成功 一直卡着
喜欢原味奶茶 2019-11-02
  • 打赏
  • 举报
回复
有几种可能性: 1、网络延迟 2、前端调用这个update的js里是不是卡住了,做了什么其他操作,导致从点击到提交相隔的时间有点长。 3、你所说的用户点击是10点13,日志是10点43,这个你确定服务器的时间和用户电脑时间是同步的吗。
小组长 2019-11-02
  • 打赏
  • 举报
回复
你发送的时候有没有需要转换编码的地方
傻蛋丫 2019-10-31
  • 打赏
  • 举报
回复
敌军30s就到达战场了,这30min基地都被推了
m0_37105523 2019-10-31
  • 打赏
  • 举报
回复
大家说的方法容我先试试,这个bug目前就出现过两次 还是间隔一周 下次出现的时候应该叫就能有结果了
maradona1984 2019-10-31
  • 打赏
  • 举报
回复
估计锁表了,你这日志都sql,没看到请求的日志,数据源设置下超时时间吧
m0_37105523 2019-10-31
  • 打赏
  • 举报
回复
发送update的ajax之前还发送了一个数值校验check check成功后再发送update
但是之前的check都成功了
第一次校验过了三十分钟后 tomcat才一次记录了好多update请求
m0_37105523 2019-10-31
  • 打赏
  • 举报
回复
有没有可能跟ajax嵌套有关系
m0_37105523 2019-10-30
  • 打赏
  • 举报
回复
引用 6 楼 hai_tong_yi_de 的回复:
每次都是30分钟还是就只有这一次是30分钟,我最近也遇到这样的问题了
这是第一次统计时间 所以还不确定
情谊梦幻 2019-10-30
  • 打赏
  • 举报
回复
重现不了就重写吧!
m0_37105523 2019-10-30
  • 打赏
  • 举报
回复
卡住的时候其他请求方法不受影响 只有这个update卡住了
m0_37105523 2019-10-30
  • 打赏
  • 举报
回复
引用 1 楼 情谊梦幻 的回复:
前后端都debug试一下,看看是哪里速度慢了,一步步走下去查看原因

这个是偶发性的 不知道怎么重现 之前卡住半小时后 再执行操作就又没问题了
u011050664 2019-10-30
  • 打赏
  • 举报
回复
30分钟能绕地球N圈了
情谊梦幻 2019-10-30
  • 打赏
  • 举报
回复
前后端都debug试一下,看看是哪里速度慢了,一步步走下去查看原因
  • 打赏
  • 举报
回复
在刚进入后台的地方断点下,加个日志,看看是否是请求到了后台,update操作一直在等待。如果是update操作等待可能是表被锁了。或者是修改操作未提交等。如果进入后台前就卡主了。可以给ajax添加timeout : 1000,设置超时时间,看下石佛事网络原因。
加载更多回复(1)

81,092

社区成员

发帖
与我相关
我的任务
社区描述
Java Web 开发
社区管理员
  • Web 开发社区
加入社区
  • 近7日
  • 近30日
  • 至今
社区公告
暂无公告

试试用AI创作助手写篇文章吧