incubator-hugegraph icon indicating copy to clipboard operation
incubator-hugegraph copied to clipboard

[Question] pg 做后端启动一段时间后, server运行异常提示连接已关闭

Open ingla9988 opened this issue 4 years ago • 9 comments

Problem Type (问题类型)

No response

Before submit

  • [X] 我已经确认现有的 IssuesFAQ 中没有相同 / 重复问题

Environment (环境信息)

  • Server Version: v0.11.2
  • Backend: pg
  • OS: 4 CPUs, 15 G RAM, Centos 7.2
  • Data Size: xx vertices, xx edges

Your Question (问题描述)

数据量很少,基本上没啥数据,但是不知道为啥过段时间 操作就会报错如下? 连接后端pg异常? 但是数据库是很正常的 ,重启hugegraph-server进程可以解决,但是过段时间又出现了,是和pg交互有什么bug吗?

2021-07-08 21:24:33 802156586 [task-scheduler-1] [ERROR] com.baidu.hugegraph.task.TaskManager [] - Exception occurred when schedule job
com.baidu.hugegraph.HugeException: Failed to update/query server info: java.util.concurrent.ExecutionException: com.baidu.hugegraph.backend.BackendException: Failed to query [`Query * f
rom VERTEX where id in [Sserver-1]`]
        at com.baidu.hugegraph.task.ServerInfoManager.call(ServerInfoManager.java:318) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.ServerInfoManager.serverInfo(ServerInfoManager.java:327) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.ServerInfoManager.selfServerInfo(ServerInfoManager.java:323) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.ServerInfoManager.heartbeat(ServerInfoManager.java:186) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.TaskManager.scheduleOrExecuteJobForGraph(TaskManager.java:292) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.TaskManager.scheduleOrExecuteJob(TaskManager.java:258) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_181]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_181]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_181]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_181]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_181]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_181]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_181]
Caused by: java.util.concurrent.ExecutionException: com.baidu.hugegraph.backend.BackendException: Failed to query [`Query * from VERTEX where id in [Sserver-1]`]
        at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_181]
        at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_181]
        at com.baidu.hugegraph.task.ServerInfoManager.call(ServerInfoManager.java:315) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        ... 12 more
Caused by: com.baidu.hugegraph.backend.BackendException: Failed to query [`Query * from VERTEX where id in [Sserver-1]`]
        at com.baidu.hugegraph.backend.store.mysql.MysqlTable.query(MysqlTable.java:371) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.store.mysql.MysqlTable.query(MysqlTable.java:351) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.store.mysql.MysqlStore.query(MysqlStore.java:273) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.tx.AbstractTransaction.query(AbstractTransaction.java:166) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.query(GraphTransaction.java:516) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.queryVerticesFromBackend(GraphTransaction.java:756) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.queryVerticesByIds(GraphTransaction.java:710) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.queryVertices(GraphTransaction.java:664) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.ServerInfoManager.lambda$serverInfo$4(ServerInfoManager.java:328) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.TaskManager$ContextCallable.call(TaskManager.java:344) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_181]
        ... 3 more
Caused by: org.postgresql.util.PSQLException: This connection has been closed.
        at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:766) ~[postgresql-42.1.4.jar:42.1.4]
        at org.postgresql.jdbc.PgConnection.createStatement(PgConnection.java:1576) ~[postgresql-42.1.4.jar:42.1.4]
        at org.postgresql.jdbc.PgConnection.createStatement(PgConnection.java:367) ~[postgresql-42.1.4.jar:42.1.4]
        at com.baidu.hugegraph.backend.store.mysql.MysqlSessions$Session.select(MysqlSessions.java:469) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.store.mysql.MysqlTable.query(MysqlTable.java:367) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.store.mysql.MysqlTable.query(MysqlTable.java:351) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.store.mysql.MysqlStore.query(MysqlStore.java:273) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.tx.AbstractTransaction.query(AbstractTransaction.java:166) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.query(GraphTransaction.java:516) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.queryVerticesFromBackend(GraphTransaction.java:756) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.queryVerticesByIds(GraphTransaction.java:710) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.queryVertices(GraphTransaction.java:664) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.ServerInfoManager.lambda$serverInfo$4(ServerInfoManager.java:328) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.task.TaskManager$ContextCallable.call(TaskManager.java:344) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_181]
        ... 3 more

2021-07-09 11:50:01 854084528 [gremlin-server-exec-3] [WARN ] org.apache.tinkerpop.gremlin.server.handler.HttpGremlinEndpointHandler [] - Invalid request - responding with 500 Internal Server Error and This connection has been closed.
org.postgresql.util.PSQLException: This connection has been closed.
        at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:766) ~[postgresql-42.1.4.jar:42.1.4]
        at org.postgresql.jdbc.PgConnection.createStatement(PgConnection.java:1576) ~[postgresql-42.1.4.jar:42.1.4]
        at org.postgresql.jdbc.PgConnection.createStatement(PgConnection.java:367) ~[postgresql-42.1.4.jar:42.1.4]
        at com.baidu.hugegraph.backend.store.mysql.MysqlSessions$Session.select(MysqlSessions.java:469) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.store.mysql.MysqlTable.query(MysqlTable.java:367) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.store.mysql.MysqlTable.query(MysqlTable.java:351) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.store.mysql.MysqlStore.query(MysqlStore.java:273) ~[hugegraph-mysql-0.11.2.jar:?]
        at com.baidu.hugegraph.backend.tx.AbstractTransaction.query(AbstractTransaction.java:166) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.lambda$query$0(GraphTransaction.java:520) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.page.QueryList$OptimizedQuery.iterator(QueryList.java:161) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.page.QueryList.lambda$fetch$0(QueryList.java:100) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.query.QueryResults.lambda$flatMap$1(QueryResults.java:207) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.iterator.FlatMapperIterator.fetch(FlatMapperIterator.java:62) ~[hugegraph-common-1.8.1.jar:1.8.1.0]
        at com.baidu.hugegraph.iterator.WrappedIterator.hasNext(WrappedIterator.java:40) ~[hugegraph-common-1.8.1.jar:1.8.1.0]
        at com.baidu.hugegraph.iterator.MapperIterator.fetch(MapperIterator.java:42) ~[hugegraph-common-1.8.1.jar:1.8.1.0]
        at com.baidu.hugegraph.iterator.WrappedIterator.hasNext(WrappedIterator.java:40) ~[hugegraph-common-1.8.1.jar:1.8.1.0]
        at com.baidu.hugegraph.iterator.FilterIterator.fetch(FilterIterator.java:42) ~[hugegraph-common-1.8.1.jar:1.8.1.0]
        at com.baidu.hugegraph.iterator.WrappedIterator.hasNext(WrappedIterator.java:40) ~[hugegraph-common-1.8.1.jar:1.8.1.0]
        at com.baidu.hugegraph.backend.query.QueryResults.keepInputOrderIfNeeded(QueryResults.java:102) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.queryVerticesFromBackend(GraphTransaction.java:765) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.cache.CachedGraphTransaction.queryVerticesFromBackend(CachedGraphTransaction.java:186) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.backend.tx.GraphTransaction.queryVertices(GraphTransaction.java:745) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.StandardHugeGraph.vertices(StandardHugeGraph.java:557) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.traversal.optimize.HugeGraphStep.vertices(HugeGraphStep.java:117) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at com.baidu.hugegraph.traversal.optimize.HugeGraphStep.lambda$new$0(HugeGraphStep.java:68) ~[hugegraph-core-0.11.2.jar:0.11.2.0]
        at org.apache.tinkerpop.gremlin.process.traversal.step.map.GraphStep.processNextStart(GraphStep.java:155) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(AbstractStep.java:143) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.process.traversal.step.util.ExpandableStepIterator.next(ExpandableStepIterator.java:50) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.process.traversal.step.map.FlatMapStep.processNextStart(FlatMapStep.java:48) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext(AbstractStep.java:143) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.process.traversal.util.DefaultTraversal.hasNext(DefaultTraversal.java:197) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.util.iterator.IteratorUtils.fill(IteratorUtils.java:62) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.util.iterator.IteratorUtils.list(IteratorUtils.java:85) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.util.iterator.IteratorUtils.asList(IteratorUtils.java:382) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.server.handler.HttpGremlinEndpointHandler.lambda$channelRead$1(HttpGremlinEndpointHandler.java:245) ~[gremlin-server-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.util.function.FunctionUtils.lambda$wrapFunction$0(FunctionUtils.java:36) ~[gremlin-core-3.4.3.jar:3.4.3]
        at org.apache.tinkerpop.gremlin.groovy.engine.GremlinExecutor.lambda$eval$0(GremlinExecutor.java:272) ~[gremlin-groovy-3.4.3.jar:3.4.3]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_181]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_181]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_181]
        at com.baidu.hugegraph.auth.HugeGraphAuthProxy$ContextTask.run(HugeGraphAuthProxy.java:1537) [hugegraph-api-0.11.2.jar:0.58.0.0]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_181]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_181]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_181]

Vertex/Edge example (问题点 / 边数据举例)

No response

Schema [VertexLabel, EdgeLabel, IndexLabel] (元数据结构)

No response

ingla9988 avatar Jul 13 '21 12:07 ingla9988

看起来有点像 Mysql 那连接中断类似的问题, 你可以搜一下 issue 有几个关于 mysql 超过时间没有请求自动断开的问题 也有提供对应的参数, 在 Mysql5.x 是有效的, 你可以看看是不是类似的情况

或者你写个小测试, 定时给 pg 那边发一个读请求保持连接, 看看是不是就不会出现这种报错了

imbajin avatar Jul 14 '21 05:07 imbajin

看起来有点像 Mysql 那连接中断类似的问题, 你可以搜一下 issue 有几个关于 mysql 超过时间没有请求自动断开的问题 也有提供对应的参数, 在 Mysql5.x 是有效的, 你可以看看是不是类似的情况

或者你写个小测试, 定时给 pg 那边发一个读请求保持连接, 看看是不是就不会出现这种报错了

写小程序测试没有用吧? 这个是hugeserver和后端pg的问题,现在是运行一段时间后没操作的话,server进程直接退出了

ingla9988 avatar Jul 19 '21 08:07 ingla9988

我是说调用 HugeClient 写个小程序, 让 server 和 PG 定时发个消息, 可以先看看之前的 mysql 断开的 issues

imbajin avatar Jul 19 '21 10:07 imbajin

槽点确认!Postgres、MYSQL作为存储端都存在连接上的通病

cleverpig avatar Jul 20 '21 00:07 cleverpig

槽点确认!Postgres、MYSQL 作为存储端都存在连接上的通病

lol, 没记错它们两个走的连接是一个方式, 因为它们两不是主要的生产支持存储, 所以最早是先支持跑通, 并没有多花时间在这上面

imbajin avatar Jul 20 '21 03:07 imbajin

好的,谢谢,我先试下,另外咨询下, hugeserver端与后端pg和mysql的交互,什么时候可以支持连接池?

ingla9988 avatar Jul 22 '21 01:07 ingla9988

好的,谢谢,我先试下,另外咨询下, hugeserver 端与后端 pg 和 mysql 的交互,什么时候可以支持连接池?

如果引入外置连接池的话, 熟悉稳定的库应该很快吧, 就是需要有时间测试和实际运行一下, 有熟悉的同学可以帮忙提个 PR 么 ~

目前有其他分布式存算安排, 可能还没定这个排期呢. 标记一下先

imbajin avatar Jul 22 '21 03:07 imbajin

这个问题可能跟 #1626 有关,如果是的话,0.12.0版本已解决该问题,请使用0.12.0版再试试?

javeme avatar Jan 04 '22 04:01 javeme

用的 1.2 版本还是存在这个问题...

fishisnow avatar Feb 04 '24 07:02 fishisnow