Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG]node-controller内存泄露 #29586

Closed
fy556 opened this issue Mar 18, 2024 · 4 comments
Closed

[BUG]node-controller内存泄露 #29586

fy556 opened this issue Mar 18, 2024 · 4 comments
Assignees
@youliyuan-fit2cloud
Labels
状态:待用户反馈

Comments

@fy556
Copy link

fy556 commented Mar 18, 2024 •
edited
Loading

联系方式

MeterSphere 版本

v2.10.12-lts

使用外置数据库

否

问题描述

v2.10.5-lts版本在线升级到v2.10.12-Lts版本后，执行接口测试案例，会导致node-controller服务挂掉重启

重现步骤

接口测试案例中，有使用前置步骤，前置步骤中 有配置mysql数据库，通过前置步骤 从数据库中 写sql ，获取数据，由于写的sql获取的表数据当有大量数据时，被测sql语句获取数据id有470w条雪花id，此时可以通过在安装ms服务器上使用docker stats查看观察到
node-controller服务 内存不断增加 ，达到600-700多M时，容器挂掉重启；而node-controller服务容器，默认是1g 使用的运行内存，正常调用接口时，内存使用在200-400m左右正常使用范围；此时将docker-compose node-controller yml 中默认改为8g，继续调用之前的接口测试案例，执行观察，发现内存从200m不断攀升至3.7g左右，案例执行完毕后，此时node-controller容器没有挂掉，但是内存没有释放。 再次一次执行该接口案例，内存继续攀升，则node-controller容器将挂掉重启

期待的正确结果

期望执行完毕接口后，正确释放内存

相关日志输出

2024-03-14 15:49:36,190  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:49:36 INFO 6133822e 1-1 tjr2fam6fsdnbet8y3hey9kesmuccz9f

Loading class `com.mysql.jdbc.Driver'. This is deprecated. The new driver class is `com.mysql.cj.jdbc.Driver'. The driver is automatically registered via the SPI and manual loading of the driver class is generally unnecessary.
Terminating due to java.lang.OutOfMemoryError: Java heap space
ts=2024-03-14T07:49:46.846Z caller=node_exporter.go:180 level=info msg="Starting node_exporter" version="(version=1.6.1, branch=, revision=unknown)"
ts=2024-03-14T07:49:46.846Z caller=node_exporter.go:181 level=info msg="Build context" build_context="(go=go1.21.3, platform=linux/amd64, user=, date=, tags=unknown)"
ts=2024-03-14T07:49:46.846Z caller=node_exporter.go:183 level=warn msg="Node Exporter is running as root user. This exporter is designed to run as unprivileged user, root is not required."
ts=2024-03-14T07:49:46.846Z caller=diskstats_common.go:111 level=info collector=diskstats msg="Parsed flag --collector.diskstats.device-exclude" flag=^(ram|loop|fd|(h|s|v|xv)d[a-z]|nvme\d+n\d+p)\d+$
ts=2024-03-14T07:49:46.847Z caller=diskstats_linux.go:265 level=error collector=diskstats msg="Failed to open directory, disabling udev device properties" path=/run/udev/data
ts=2024-03-14T07:49:46.848Z caller=filesystem_common.go:111 level=info collector=filesystem msg="Parsed flag --collector.filesystem.mount-points-exclude" flag=^/(dev|proc|run/credentials/.+|sys|var/lib/docker/.+|var/lib/containers/storage/.+)($|/)
ts=2024-03-14T07:49:46.848Z caller=filesystem_common.go:113 level=info collector=filesystem msg="Parsed flag --collector.filesystem.fs-types-exclude" flag=^(autofs|binfmt_misc|bpf|cgroup2?|configfs|debugfs|devpts|devtmpfs|fusectl|hugetlbfs|iso9660|mqueue|nsfs|overlay|proc|procfs|pstore|rpc_pipefs|securityfs|selinuxfs|squashfs|sysfs|tracefs)$
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:110 level=info msg="Enabled collectors"
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=arp
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=bcache
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=bonding
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=btrfs
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=conntrack
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=cpu
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=cpufreq
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=diskstats
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=dmi
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=edac
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=entropy
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=fibrechannel
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=filefd
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=filesystem
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=hwmon
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=infiniband
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=ipvs
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=loadavg
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=mdadm
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=meminfo
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=netclass
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=netdev
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=netstat
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=nfs
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=nfsd
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=nvme
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=os
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=powersupplyclass
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=pressure
ts=2024-03-14T07:49:46.849Z caller=node_exporter.go:117 level=info collector=rapl
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=schedstat
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=selinux
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=sockstat
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=softnet
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=stat
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=tapestats
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=textfile
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=thermal_zone
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=time
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=timex
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=udp_queues
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=uname
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=vmstat
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=xfs
ts=2024-03-14T07:49:46.850Z caller=node_exporter.go:117 level=info collector=zfs
ts=2024-03-14T07:49:46.851Z caller=tls_config.go:274 level=info msg="Listening on" address=[::]:9100
ts=2024-03-14T07:49:46.851Z caller=tls_config.go:277 level=info msg="TLS is disabled." http2=false address=[::]:9100
exec java -Dfile.encoding=utf-8 -Djava.awt.headless=true --add-opens java.base/jdk.internal.loader=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED -Xmx410m -XX:+ExitOnOutOfMemoryError -cp /app:/app/lib/ms-jmeter-core.jar:/opt/jmeter/lib/ext/*:/app/lib/* io.metersphere.Application
15:49:47,794 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - <level> element is deprecated. Near [level] on line 184
15:49:47,794 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - Please use "level" attribute within <logger> or <root> elements instead.
15:49:47,794 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - <level> element is deprecated. Near [level] on line 195
15:49:47,794 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - Please use "level" attribute within <logger> or <root> elements instead.
15:49:47,952 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [console]
15:49:47,953 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
15:49:47,968 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:48,022 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [debugAppender]
15:49:48,022 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:48,058 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@2032079962 - No compression will be used
15:49:48,065 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@2032079962 - Will use the pattern /opt/metersphere/logs/node-controller/history/debug.%d{yyyyMMdd}-%i.log for the active file
15:49:48,115 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3e27aa33 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/debug.%d{yyyyMMdd}-%i.log'.
15:49:48,115 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3e27aa33 - Roll-over at midnight.
15:49:48,127 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3e27aa33 - Setting initial period to 2023-08-07T06:23:38.930Z
15:49:48,127 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3e27aa33 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:48,127 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3e27aa33 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:48,133 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:48,139 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[debugAppender] - Active log file name: /opt/metersphere/logs/node-controller/debug.log
15:49:48,139 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[debugAppender] - File property is set to [/opt/metersphere/logs/node-controller/debug.log]
15:49:48,141 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [infoAppender]
15:49:48,141 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:48,144 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1042790962 - No compression will be used
15:49:48,144 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1042790962 - Will use the pattern /opt/metersphere/logs/node-controller/history/info.%d{yyyyMMdd}-%i.log for the active file
15:49:48,145 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7ef82753 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/info.%d{yyyyMMdd}-%i.log'.
15:49:48,145 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7ef82753 - Roll-over at midnight.
15:49:48,145 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7ef82753 - Setting initial period to 2024-03-14T07:49:36.189Z
15:49:48,146 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7ef82753 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:48,146 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7ef82753 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:48,147 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:48,148 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[infoAppender] - Active log file name: /opt/metersphere/logs/node-controller/info.log
15:49:48,148 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[infoAppender] - File property is set to [/opt/metersphere/logs/node-controller/info.log]
15:49:48,148 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [errorAppender]
15:49:48,148 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:48,150 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@990897274 - No compression will be used
15:49:48,150 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@990897274 - Will use the pattern /opt/metersphere/logs/node-controller/history/error.%d{yyyyMMdd}-%i.log for the active file
15:49:48,151 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@202b0582 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/error.%d{yyyyMMdd}-%i.log'.
15:49:48,151 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@202b0582 - Roll-over at midnight.
15:49:48,151 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@202b0582 - Setting initial period to 2023-08-07T03:39:45.538Z
15:49:48,152 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@202b0582 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:48,152 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@202b0582 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:48,152 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:48,154 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[errorAppender] - Active log file name: /opt/metersphere/logs/node-controller/error.log
15:49:48,154 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[errorAppender] - File property is set to [/opt/metersphere/logs/node-controller/error.log]
15:49:48,154 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [warnAppender]
15:49:48,154 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:48,155 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@593415583 - No compression will be used
15:49:48,156 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@593415583 - Will use the pattern /opt/metersphere/logs/node-controller/history/warn.%d{yyyyMMdd}-%i.log for the active file
15:49:48,156 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1ca3b418 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/warn.%d{yyyyMMdd}-%i.log'.
15:49:48,156 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1ca3b418 - Roll-over at midnight.
15:49:48,157 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1ca3b418 - Setting initial period to 2023-08-07T03:39:45.543Z
15:49:48,157 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1ca3b418 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:48,157 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@1ca3b418 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:48,158 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:48,159 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[warnAppender] - Active log file name: /opt/metersphere/logs/node-controller/warn.log
15:49:48,159 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[warnAppender] - File property is set to [/opt/metersphere/logs/node-controller/warn.log]
15:49:48,160 |-WARN in ch.qos.logback.core.model.processor.AppenderModelHandler - Appender named [consoleAsyncAppender] not referenced. Skipping further processing.
15:49:48,160 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [debugAsyncAppender]
15:49:48,160 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:48,164 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [debugAppender] to ch.qos.logback.classic.AsyncAppender[debugAsyncAppender]
15:49:48,165 |-INFO in ch.qos.logback.classic.AsyncAppender[debugAsyncAppender] - Attaching appender named [debugAppender] to AsyncAppender.
15:49:48,166 |-INFO in ch.qos.logback.classic.AsyncAppender[debugAsyncAppender] - Setting discardingThreshold to 2000
15:49:48,166 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [infoAsyncAppender]
15:49:48,166 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:48,167 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAppender] to ch.qos.logback.classic.AsyncAppender[infoAsyncAppender]
15:49:48,167 |-INFO in ch.qos.logback.classic.AsyncAppender[infoAsyncAppender] - Attaching appender named [infoAppender] to AsyncAppender.
15:49:48,167 |-INFO in ch.qos.logback.classic.AsyncAppender[infoAsyncAppender] - Setting discardingThreshold to 2000
15:49:48,168 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [errorAsyncAppender]
15:49:48,168 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:48,168 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [errorAppender] to ch.qos.logback.classic.AsyncAppender[errorAsyncAppender]
15:49:48,168 |-INFO in ch.qos.logback.classic.AsyncAppender[errorAsyncAppender] - Attaching appender named [errorAppender] to AsyncAppender.
15:49:48,168 |-INFO in ch.qos.logback.classic.AsyncAppender[errorAsyncAppender] - Setting discardingThreshold to 2000
15:49:48,169 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [warnAsyncAppender]
15:49:48,169 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:48,169 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [warnAppender] to ch.qos.logback.classic.AsyncAppender[warnAsyncAppender]
15:49:48,169 |-INFO in ch.qos.logback.classic.AsyncAppender[warnAsyncAppender] - Attaching appender named [warnAppender] to AsyncAppender.
15:49:48,170 |-INFO in ch.qos.logback.classic.AsyncAppender[warnAsyncAppender] - Setting discardingThreshold to 2000
15:49:48,170 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [JMETER_LOG]
15:49:48,170 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [io.metersphere.api.jmeter.JMeterLoggerAppender]
15:49:48,173 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to INFO
15:49:48,174 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAsyncAppender] to Logger[ROOT]
15:49:48,174 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [console] to Logger[ROOT]
15:49:48,176 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.apache.jmeter] to DEBUG
15:49:48,177 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [org.apache.jmeter] to false
15:49:48,177 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [JMETER_LOG] to Logger[org.apache.jmeter]
15:49:48,177 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [apiRunLogAppender]
15:49:48,177 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:48,179 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@95396809 - No compression will be used
15:49:48,179 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@95396809 - Will use the pattern /opt/metersphere/logs/node-controller/history/ms-jmeter-run.%d{yyyyMMdd}-%i.log for the active file
15:49:48,180 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@72035809 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/ms-jmeter-run.%d{yyyyMMdd}-%i.log'.
15:49:48,180 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@72035809 - Roll-over at midnight.
15:49:48,180 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@72035809 - Setting initial period to 2024-03-14T07:49:35.141Z
15:49:48,180 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@72035809 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:48,181 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@72035809 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:48,181 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:48,182 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[apiRunLogAppender] - Active log file name: /opt/metersphere/logs/node-controller/ms-jmeter-run.log
15:49:48,183 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[apiRunLogAppender] - File property is set to [/opt/metersphere/logs/node-controller/ms-jmeter-run.log]
15:49:48,183 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [runLogAppender]
15:49:48,183 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:48,183 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [apiRunLogAppender] to ch.qos.logback.classic.AsyncAppender[runLogAppender]
15:49:48,183 |-INFO in ch.qos.logback.classic.AsyncAppender[runLogAppender] - Attaching appender named [apiRunLogAppender] to AsyncAppender.
15:49:48,184 |-INFO in ch.qos.logback.classic.AsyncAppender[runLogAppender] - Setting discardingThreshold to 2000
15:49:48,184 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [ms-jmeter-run-log] to false
15:49:48,185 |-INFO in ch.qos.logback.classic.model.processor.LevelModelHandler - ms-jmeter-run-log level set to DEBUG
15:49:48,185 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [runLogAppender] to Logger[ms-jmeter-run-log]
15:49:48,185 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to INFO
15:49:48,185 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAsyncAppender] to Logger[ROOT]
15:49:48,185 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [console] to Logger[ROOT]
15:49:48,185 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [io.metersphere] to false
15:49:48,185 |-INFO in ch.qos.logback.classic.model.processor.LevelModelHandler - io.metersphere level set to DEBUG
15:49:48,185 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [debugAsyncAppender] to Logger[io.metersphere]
15:49:48,186 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAsyncAppender] to Logger[io.metersphere]
15:49:48,186 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [warnAsyncAppender] to Logger[io.metersphere]
15:49:48,186 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [errorAsyncAppender] to Logger[io.metersphere]
15:49:48,186 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [io.metersphere.Application] to DEBUG
15:49:48,186 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [io.metersphere.Application] to false
15:49:48,186 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAsyncAppender] to Logger[io.metersphere.Application]
15:49:48,186 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@909217e - End of configuration.
15:49:48,188 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@48075da3 - Registering current configuration as safe fallback point
15:49:48,188 |-INFO in ch.qos.logback.classic.util.ContextInitializer@68c9133c - ch.qos.logback.classic.util.DefaultJoranConfigurator.configure() call lasted 720 milliseconds. ExecutionStatus=DO_NOT_INVOKE_NEXT_IF_ANY
15:49:49,302 |-INFO in ch.qos.logback.classic.AsyncAppender[infoAsyncAppender] - Worker thread will flush remaining events before exiting.
15:49:49,303 |-INFO in ch.qos.logback.classic.AsyncAppender[infoAsyncAppender] - Queue flush finished successfully within timeout.
15:49:49,304 |-INFO in ch.qos.logback.classic.AsyncAppender[runLogAppender] - Worker thread will flush remaining events before exiting.
15:49:49,304 |-INFO in ch.qos.logback.classic.AsyncAppender[runLogAppender] - Queue flush finished successfully within timeout.
15:49:49,304 |-INFO in ch.qos.logback.classic.AsyncAppender[debugAsyncAppender] - Worker thread will flush remaining events before exiting.
15:49:49,305 |-INFO in ch.qos.logback.classic.AsyncAppender[debugAsyncAppender] - Queue flush finished successfully within timeout.
15:49:49,305 |-INFO in ch.qos.logback.classic.AsyncAppender[warnAsyncAppender] - Worker thread will flush remaining events before exiting.
15:49:49,305 |-INFO in ch.qos.logback.classic.AsyncAppender[warnAsyncAppender] - Queue flush finished successfully within timeout.
15:49:49,305 |-INFO in ch.qos.logback.classic.AsyncAppender[errorAsyncAppender] - Worker thread will flush remaining events before exiting.
15:49:49,306 |-INFO in ch.qos.logback.classic.AsyncAppender[errorAsyncAppender] - Queue flush finished successfully within timeout.
15:49:49,302 |-INFO in ch.qos.logback.classic.AsyncAppender[infoAsyncAppender] - Worker thread will flush remaining events before exiting.
15:49:49,303 |-INFO in ch.qos.logback.classic.AsyncAppender[infoAsyncAppender] - Queue flush finished successfully within timeout.
15:49:49,304 |-INFO in ch.qos.logback.classic.AsyncAppender[runLogAppender] - Worker thread will flush remaining events before exiting.
15:49:49,304 |-INFO in ch.qos.logback.classic.AsyncAppender[runLogAppender] - Queue flush finished successfully within timeout.
15:49:49,304 |-INFO in ch.qos.logback.classic.AsyncAppender[debugAsyncAppender] - Worker thread will flush remaining events before exiting.
15:49:49,305 |-INFO in ch.qos.logback.classic.AsyncAppender[debugAsyncAppender] - Queue flush finished successfully within timeout.
15:49:49,305 |-INFO in ch.qos.logback.classic.AsyncAppender[warnAsyncAppender] - Worker thread will flush remaining events before exiting.
15:49:49,305 |-INFO in ch.qos.logback.classic.AsyncAppender[warnAsyncAppender] - Queue flush finished successfully within timeout.
15:49:49,305 |-INFO in ch.qos.logback.classic.AsyncAppender[errorAsyncAppender] - Worker thread will flush remaining events before exiting.
15:49:49,306 |-INFO in ch.qos.logback.classic.AsyncAppender[errorAsyncAppender] - Queue flush finished successfully within timeout.
15:49:49,335 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - <level> element is deprecated. Near [level] on line 184
15:49:49,335 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - Please use "level" attribute within <logger> or <root> elements instead.
15:49:49,335 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - <level> element is deprecated. Near [level] on line 195
15:49:49,335 |-WARN in ch.qos.logback.classic.joran.action.LevelAction - Please use "level" attribute within <logger> or <root> elements instead.
15:49:49,341 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [console]
15:49:49,341 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
15:49:49,342 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:49,343 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [debugAppender]
15:49:49,343 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:49,345 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@550572371 - No compression will be used
15:49:49,345 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@550572371 - Will use the pattern /opt/metersphere/logs/node-controller/history/debug.%d{yyyyMMdd}-%i.log for the active file
15:49:49,346 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3887cf88 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/debug.%d{yyyyMMdd}-%i.log'.
15:49:49,346 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3887cf88 - Roll-over at midnight.
15:49:49,346 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3887cf88 - Setting initial period to 2023-08-07T06:23:38.930Z
15:49:49,347 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3887cf88 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:49,347 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@3887cf88 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:49,347 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:49,348 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[debugAppender] - Active log file name: /opt/metersphere/logs/node-controller/debug.log
15:49:49,348 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[debugAppender] - File property is set to [/opt/metersphere/logs/node-controller/debug.log]
15:49:49,349 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [infoAppender]
15:49:49,349 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:49,350 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1447685190 - No compression will be used
15:49:49,350 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1447685190 - Will use the pattern /opt/metersphere/logs/node-controller/history/info.%d{yyyyMMdd}-%i.log for the active file
15:49:49,351 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@78dc4696 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/info.%d{yyyyMMdd}-%i.log'.
15:49:49,351 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@78dc4696 - Roll-over at midnight.
15:49:49,351 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@78dc4696 - Setting initial period to 2024-03-14T07:49:36.189Z
15:49:49,351 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@78dc4696 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:49,351 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@78dc4696 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:49,352 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:49,353 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[infoAppender] - Active log file name: /opt/metersphere/logs/node-controller/info.log
15:49:49,353 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[infoAppender] - File property is set to [/opt/metersphere/logs/node-controller/info.log]
15:49:49,353 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [errorAppender]
15:49:49,353 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:49,354 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1345293143 - No compression will be used
15:49:49,356 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1345293143 - Will use the pattern /opt/metersphere/logs/node-controller/history/error.%d{yyyyMMdd}-%i.log for the active file
15:49:49,356 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@38f2e97e - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/error.%d{yyyyMMdd}-%i.log'.
15:49:49,356 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@38f2e97e - Roll-over at midnight.
15:49:49,357 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@38f2e97e - Setting initial period to 2023-08-07T03:39:45.538Z
15:49:49,357 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@38f2e97e - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:49,357 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@38f2e97e - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:49,357 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:49,358 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[errorAppender] - Active log file name: /opt/metersphere/logs/node-controller/error.log
15:49:49,358 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[errorAppender] - File property is set to [/opt/metersphere/logs/node-controller/error.log]
15:49:49,359 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [warnAppender]
15:49:49,359 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:49,360 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@2006842965 - No compression will be used
15:49:49,360 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@2006842965 - Will use the pattern /opt/metersphere/logs/node-controller/history/warn.%d{yyyyMMdd}-%i.log for the active file
15:49:49,360 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@323659f8 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/warn.%d{yyyyMMdd}-%i.log'.
15:49:49,361 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@323659f8 - Roll-over at midnight.
15:49:49,361 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@323659f8 - Setting initial period to 2023-08-07T03:39:45.543Z
15:49:49,361 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@323659f8 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:49,361 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@323659f8 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:49,362 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:49,362 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[warnAppender] - Active log file name: /opt/metersphere/logs/node-controller/warn.log
15:49:49,362 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[warnAppender] - File property is set to [/opt/metersphere/logs/node-controller/warn.log]
15:49:49,363 |-WARN in ch.qos.logback.core.model.processor.AppenderModelHandler - Appender named [consoleAsyncAppender] not referenced. Skipping further processing.
15:49:49,363 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [debugAsyncAppender]
15:49:49,363 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:49,363 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [debugAppender] to ch.qos.logback.classic.AsyncAppender[debugAsyncAppender]
15:49:49,363 |-INFO in ch.qos.logback.classic.AsyncAppender[debugAsyncAppender] - Attaching appender named [debugAppender] to AsyncAppender.
15:49:49,363 |-INFO in ch.qos.logback.classic.AsyncAppender[debugAsyncAppender] - Setting discardingThreshold to 2000
15:49:49,364 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [infoAsyncAppender]
15:49:49,364 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:49,365 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAppender] to ch.qos.logback.classic.AsyncAppender[infoAsyncAppender]
15:49:49,365 |-INFO in ch.qos.logback.classic.AsyncAppender[infoAsyncAppender] - Attaching appender named [infoAppender] to AsyncAppender.
15:49:49,365 |-INFO in ch.qos.logback.classic.AsyncAppender[infoAsyncAppender] - Setting discardingThreshold to 2000
15:49:49,366 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [errorAsyncAppender]
15:49:49,366 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:49,366 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [errorAppender] to ch.qos.logback.classic.AsyncAppender[errorAsyncAppender]
15:49:49,366 |-INFO in ch.qos.logback.classic.AsyncAppender[errorAsyncAppender] - Attaching appender named [errorAppender] to AsyncAppender.
15:49:49,366 |-INFO in ch.qos.logback.classic.AsyncAppender[errorAsyncAppender] - Setting discardingThreshold to 2000
15:49:49,367 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [warnAsyncAppender]
15:49:49,367 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:49,367 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [warnAppender] to ch.qos.logback.classic.AsyncAppender[warnAsyncAppender]
15:49:49,367 |-INFO in ch.qos.logback.classic.AsyncAppender[warnAsyncAppender] - Attaching appender named [warnAppender] to AsyncAppender.
15:49:49,367 |-INFO in ch.qos.logback.classic.AsyncAppender[warnAsyncAppender] - Setting discardingThreshold to 2000
15:49:49,368 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [JMETER_LOG]
15:49:49,368 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [io.metersphere.api.jmeter.JMeterLoggerAppender]
15:49:49,368 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to INFO
15:49:49,369 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@26a529dc - Propagating INFO level on Logger[ROOT] onto the JUL framework
15:49:49,370 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAsyncAppender] to Logger[ROOT]
15:49:49,370 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [console] to Logger[ROOT]
15:49:49,370 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [org.apache.jmeter] to DEBUG
15:49:49,370 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@26a529dc - Propagating DEBUG level on Logger[org.apache.jmeter] onto the JUL framework
15:49:49,370 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [org.apache.jmeter] to false
15:49:49,370 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [JMETER_LOG] to Logger[org.apache.jmeter]
15:49:49,370 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [apiRunLogAppender]
15:49:49,370 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
15:49:49,371 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1466413743 - No compression will be used
15:49:49,372 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy@1466413743 - Will use the pattern /opt/metersphere/logs/node-controller/history/ms-jmeter-run.%d{yyyyMMdd}-%i.log for the active file
15:49:49,372 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7b22ec89 - The date pattern is 'yyyyMMdd' from file name pattern '/opt/metersphere/logs/node-controller/history/ms-jmeter-run.%d{yyyyMMdd}-%i.log'.
15:49:49,372 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7b22ec89 - Roll-over at midnight.
15:49:49,373 |-INFO in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7b22ec89 - Setting initial period to 2024-03-14T07:49:35.141Z
15:49:49,373 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7b22ec89 - SizeAndTimeBasedFNATP is deprecated. Use SizeAndTimeBasedRollingPolicy instead
15:49:49,373 |-WARN in ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP@7b22ec89 - For more information see http://logback.qos.ch/manual/appenders.html#SizeAndTimeBasedRollingPolicy
15:49:49,373 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
15:49:49,374 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[apiRunLogAppender] - Active log file name: /opt/metersphere/logs/node-controller/ms-jmeter-run.log
15:49:49,374 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[apiRunLogAppender] - File property is set to [/opt/metersphere/logs/node-controller/ms-jmeter-run.log]
15:49:49,374 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [runLogAppender]
15:49:49,374 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
15:49:49,375 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [apiRunLogAppender] to ch.qos.logback.classic.AsyncAppender[runLogAppender]
15:49:49,375 |-INFO in ch.qos.logback.classic.AsyncAppender[runLogAppender] - Attaching appender named [apiRunLogAppender] to AsyncAppender.
15:49:49,375 |-INFO in ch.qos.logback.classic.AsyncAppender[runLogAppender] - Setting discardingThreshold to 2000
15:49:49,375 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [ms-jmeter-run-log] to false
15:49:49,375 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@26a529dc - Propagating DEBUG level on Logger[ms-jmeter-run-log] onto the JUL framework
15:49:49,376 |-INFO in ch.qos.logback.classic.model.processor.LevelModelHandler - ms-jmeter-run-log level set to DEBUG
15:49:49,376 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [runLogAppender] to Logger[ms-jmeter-run-log]
15:49:49,376 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to INFO
15:49:49,376 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAsyncAppender] to Logger[ROOT]
15:49:49,376 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [console] to Logger[ROOT]
15:49:49,376 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [io.metersphere] to false
15:49:49,376 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@26a529dc - Propagating DEBUG level on Logger[io.metersphere] onto the JUL framework
15:49:49,376 |-INFO in ch.qos.logback.classic.model.processor.LevelModelHandler - io.metersphere level set to DEBUG
15:49:49,376 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [debugAsyncAppender] to Logger[io.metersphere]
15:49:49,376 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAsyncAppender] to Logger[io.metersphere]
15:49:49,376 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [warnAsyncAppender] to Logger[io.metersphere]
15:49:49,376 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [errorAsyncAppender] to Logger[io.metersphere]
15:49:49,376 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [io.metersphere.Application] to DEBUG
15:49:49,376 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@26a529dc - Propagating DEBUG level on Logger[io.metersphere.Application] onto the JUL framework
15:49:49,377 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [io.metersphere.Application] to false
15:49:49,377 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [infoAsyncAppender] to Logger[io.metersphere.Application]
15:49:49,377 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@241a0c3a - End of configuration.
15:49:49,377 |-INFO in org.springframework.boot.logging.logback.SpringBootJoranConfigurator@547c04c4 - Registering current configuration as safe fallback point

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v3.2.1)

2024-03-14 15:49:52,655  INFO y.config.RepositoryConfigurationDelegate: 139 - Bootstrapping Spring Data LDAP repositories in DEFAULT mode.
2024-03-14 15:49:52,839  INFO y.config.RepositoryConfigurationDelegate: 208 - Finished Spring Data repository scanning in 171 ms. Found 0 LDAP repository interfaces.
2024-03-14 15:49:54,805  INFO edded.jetty.JettyServletWebServerFactory: 184 - Server initialized with port: 8082
2024-03-14 15:49:54,814  INFO          org.eclipse.jetty.server.Server: 534 - jetty-12.0.3; built: 2023-10-27T03:25:22.284Z; git: a873259fd5af141dedaa6c7fa8fe8fbdedce0d61; jvm 17.0.10+7-alpine-r0
2024-03-14 15:49:54,890  INFO erver.handler.ContextHandler.application:2860 - Initializing Spring embedded WebApplicationContext
2024-03-14 15:49:54,893  INFO ntext.ServletWebServerApplicationContext: 296 - Root WebApplicationContext: initialization completed in 4641 ms
2024-03-14 15:49:55,676  INFO se.jetty.session.DefaultSessionIdManager: 328 - Session workerName=node0
2024-03-14 15:49:55,693  INFO ipse.jetty.server.handler.ContextHandler: 660 - Started osbwej.JettyEmbeddedWebAppContext@79424f25{application,/,b=file:/tmp/jetty-docbase.8082.9724891541830007834/,a=AVAILABLE,h=oeje10s.SessionHandler@5fd4e67f{STARTED}}
2024-03-14 15:49:55,695  INFO jetty.ee10.servlet.ServletContextHandler:1045 - Started osbwej.JettyEmbeddedWebAppContext@79424f25{application,/,b=file:/tmp/jetty-docbase.8082.9724891541830007834/,a=AVAILABLE,h=oeje10s.SessionHandler@5fd4e67f{STARTED}}
2024-03-14 15:49:55,700  INFO          org.eclipse.jetty.server.Server: 591 - Started oejs.Server@651cedfb{STARTING}[12.0.3,sto=0] @8813ms
2024-03-14 15:49:56,319  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:49:56 INFO main Setting Locale to en_US

2024-03-14 15:49:58,259  INFO tuate.endpoint.web.EndpointLinksResolver:  58 - Exposing 1 endpoint(s) beneath base path '/actuator'
2024-03-14 15:49:58,397  INFO erver.handler.ContextHandler.application:2860 - Initializing Spring DispatcherServlet 'dispatcherServlet'
2024-03-14 15:49:58,398  INFO gframework.web.servlet.DispatcherServlet: 532 - Initializing Servlet 'dispatcherServlet'
2024-03-14 15:49:58,400  INFO gframework.web.servlet.DispatcherServlet: 554 - Completed initialization in 2 ms
2024-03-14 15:49:58,420  INFO g.eclipse.jetty.server.AbstractConnector: 321 - Started ServerConnector@430a8fee{HTTP/1.1, (http/1.1)}{0.0.0.0:8082}
2024-03-14 15:49:58,423  INFO k.boot.web.embedded.jetty.JettyWebServer: 168 - Jetty started on port 8082 (http/1.1) with context path '/'
================= NODE 应用启动 START =================
sys.path: /opt/jmeter
2024-03-14 15:51:07,576  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Testplan (JMX) version: 2.2. Testlog (JTL) version: 2.2

2024-03-14 15:51:07,591  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Using SaveService properties version 5.0

2024-03-14 15:51:07,595  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Using SaveService properties file encoding UTF-8

2024-03-14 15:51:07,652  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Parser for text/html is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser

2024-03-14 15:51:07,653  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Parser for application/xhtml+xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser

2024-03-14 15:51:07,654  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Parser for application/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser

2024-03-14 15:51:07,654  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Parser for text/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser

2024-03-14 15:51:07,655  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Parser for text/vnd.wap.wml is org.apache.jmeter.protocol.http.parser.RegexpHTMLParser

2024-03-14 15:51:07,655  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO qtp1024666550-31 Parser for text/css is org.apache.jmeter.protocol.http.parser.CssParser

2024-03-14 15:51:07,689  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO MS-JMETER-RUN-TASK：1 Setting Locale to en_US

2024-03-14 15:51:07,701  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO MS-JMETER-RUN-TASK：1 Note: Sample TimeStamps are START times

2024-03-14 15:51:07,701  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO MS-JMETER-RUN-TASK：1 sampleresult.default.encoding is set to UTF-8

2024-03-14 15:51:07,702  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO MS-JMETER-RUN-TASK：1 sampleresult.useNanoTime=true

2024-03-14 15:51:07,702  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO MS-JMETER-RUN-TASK：1 sampleresult.nanoThreadSleep=5000

2024-03-14 15:51:07,721  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO StandardJMeterEngine Running the test!

2024-03-14 15:51:07,724  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO StandardJMeterEngine List of sample_variables: []

2024-03-14 15:51:07,725  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO StandardJMeterEngine List of sample_variables: []

2024-03-14 15:51:07,729  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO StandardJMeterEngine Note: Function class names must contain the string: '.functions.'

2024-03-14 15:51:07,729  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:07 INFO StandardJMeterEngine Note: Function class names must not contain the string: '.gui.'

2024-03-14 15:51:08,126  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO StandardJMeterEngine 1a46fd6c_8d1ff7d2-0154-2f86-8a52-2b82c761971e: Starting worker with class: class io.metersphere.api.jmeter.MsApiBackendListener and queue capacity: 5000

2024-03-14 15:51:08,128  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO StandardJMeterEngine 1a46fd6c_8d1ff7d2-0154-2f86-8a52-2b82c761971e: Started  worker with class: class io.metersphere.api.jmeter.MsApiBackendListener

2024-03-14 15:51:08,350  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO StandardJMeterEngine Starting ThreadGroup: 1 : 1a46fd6c

2024-03-14 15:51:08,356  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO StandardJMeterEngine Starting 1 threads for group 1a46fd6c.

2024-03-14 15:51:08,357  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO StandardJMeterEngine Thread will continue on error

2024-03-14 15:51:08,357  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO StandardJMeterEngine Starting thread group... number=1 threads=1 ramp-up=1 delayedStart=false

2024-03-14 15:51:08,365  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO StandardJMeterEngine Started thread group number 1

2024-03-14 15:51:08,366  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO StandardJMeterEngine All thread groups have been started

2024-03-14 15:51:08,367  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 Thread started: 1a46fd6c 1-1

2024-03-14 15:51:08,556  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 http://web-epw-uat.watsonsvip.com.cn/api/staff/staff-center/getMockRequest?staffNo=41245851

2024-03-14 15:51:08,650  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 source=watsons&empno=EC59FED98FCF364684FBA154A6E638BC&key=V2XFaNrf&Language=zh-CN&check=7851AB94384347D9AEAB32F56E5DF934A45C67B617EDA0BD

2024-03-14 15:51:08,659  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 a[0]：source=watsons

2024-03-14 15:51:08,661  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 a[1]：empno=EC59FED98FCF364684FBA154A6E638BC

2024-03-14 15:51:08,661  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 a[2]：key=V2XFaNrf

2024-03-14 15:51:08,662  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 a[3]：Language=zh-CN

2024-03-14 15:51:08,663  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 a[4]：check=7851AB94384347D9AEAB32F56E5DF934A45C67B617EDA0BD

2024-03-14 15:51:08,664  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 empno：EC59FED98FCF364684FBA154A6E638BC

2024-03-14 15:51:08,665  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 key：V2XFaNrf

2024-03-14 15:51:08,666  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 check：7851AB94384347D9AEAB32F56E5DF934A45C67B617EDA0BD

2024-03-14 15:51:08,670  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 http://web-epw-uat.watsonsvip.com.cn/api/staff/staff-center/auth?source=watsons&empno=EC59FED98FCF364684FBA154A6E638BC&key=V2XFaNrf&check=7851AB94384347D9AEAB32F56E5DF934A45C67B617EDA0BD

2024-03-14 15:51:08,715  INFO                                   JMETER: 227 - JMETER-LOG 2024-03-14 15:51:08 INFO 1a46fd6c 1-1 m4e8iuhgam1buimlm5skgf90stor2msl

20

附加信息

1

2
@github-actions github-actions bot added the 状态:待处理 已分配给相关处理人等待处理人处理并更新状态 label Mar 18, 2024
@fit2-zhao
Copy link
Contributor

你好，请把执行机的日志发出来我们分析一下。

@github-actions github-actions bot added 状态:待用户反馈 and removed 状态:待处理 已分配给相关处理人等待处理人处理并更新状态 labels Mar 18, 2024
@fy556
Copy link
Author

fy556 commented Mar 28, 2024

需要具体哪些日志，路径发我，我这边取一下。

@github-actions github-actions bot added 状态:待处理 已分配给相关处理人等待处理人处理并更新状态 and removed 状态:待用户反馈 labels Mar 28, 2024
@fit2-zhao
Copy link
Contributor

可以在出现问题的时候抓一份 Thread Dump 文件，具体如下：


#!/bin/bash
 
red=31
green=32
blue=34
 
function colorMsg()
{
  echo -e "\033[$1m $2 \033[0m"
}
 
MODULE=$1
OUTPUT_FILE=$2
 
if test -z "${MODULE}"
then
  colorMsg $red "[ERROR] No Module Is specified"
  exit 1
fi
 
if test -z "${OUTPUT_FILE}"
then
  colorMsg $red "[ERROR] No Output File Is specified"
  exit 1
fi
 
DOCKER_INFO_ROOT_DIR=`docker info | grep "Docker Root Dir"`
T=": "
DOCKER_ROOT=${DOCKER_INFO_ROOT_DIR##*$T}
if test -z "${DOCKER_ROOT}"
then
  colorMsg $red "[ERROR] Docker Root Dir Not Found"
  exit 1
fi
 
colorMsg $green "[OK] Docker Root Dir: ${DOCKER_ROOT}"
 
CONTAINER_ID=`docker ps |grep ${MODULE} |awk  '{print $1}'`
 
if test -z "${CONTAINER_ID}"
then
  colorMsg $red "[ERROR] Container ID Not Found"
  exit 1
fi
colorMsg $green "[OK] Container ID: ${CONTAINER_ID}"
 
LOG_FILE=`find $DOCKER_ROOT -name ${CONTAINER_ID}*-json.log`
 
if test -z "${LOG_FILE}"
then
  colorMsg $red "[ERROR] Log File Not Found"
  exit 1
fi
colorMsg $green "[OK] Container Log File: ${LOG_FILE}"
echo > ${LOG_FILE}
 
colorMsg $blue "Generating JVM Thread Dump........................ "
docker exec -it ${MODULE} kill -3 1
docker logs ${MODULE} > ${OUTPUT_FILE}
 
colorMsg $green "[OK] JVM Thread Dump Has Been Saved To ${OUTPUT_FILE}"
colorMsg $green "[DONE]"

把这段脚本转存成 dump.sh；然后执行 " sh dump.sh ms-node-controller dump.log "

把执行后的dump.log 和 /opt/metersphere/logs/node-controller 下的日志发出来就行;

@github-actions github-actions bot added 状态:待用户反馈 and removed 状态:待处理 已分配给相关处理人等待处理人处理并更新状态 labels Apr 17, 2024
@fit2-zhao fit2-zhao mentioned this issue Apr 17, 2024
Closed
@youliyuan-fit2cloud
Copy link

你好，因为长时间未反馈，暂关闭该issue，如果后续仍遇到请随时联系我们，感谢理解和支持。

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@youliyuan-fit2cloud youliyuan-fit2cloud

Labels
状态:待用户反馈
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@fy556 @youliyuan-fit2cloud @fit2-zhao