JMeter Report Dashboard 开始时间问题 1/1/70, 12:00 AM

JMeter Report Dashboard start time issue 1/1/70, 12:00 AM

我在 Jmeter 场景中遇到问题,我的仪表板报告开始时间为 Start Time "1/1/70, 12:00 AM"

结束时间正常 End Time "12/11/21, 10:04 PM"

在同一个脚本中,如果我禁用遇到此问题的线程组和 运行 另一个线程组,启动时间就可以了。这让我认为这是这个特定线程组的时间问题,而不是我的 JM props 问题。

我正在尝试使用 start/pingpong/end.

模拟长时间(1 小时以上)的 websocket 会话

据我所知,所有这些加起来就是执行所需 txns 的长 运行ning 线程,同时保持打开的 websocket 连接,并且 运行ning 正如预期的那样。

我为报告日志记录设置了 DEBUG,并没有什么不正常的事情发生在我身上。 (以下相关日志)

我在 运行 时间或其他时间自定义的唯一与报告相关的 JMeter 道具如下:

 -Jjmeter.reportgenerator.overall_granularity=$REPORTGRAN\
 -Jjmeter.reportgenerator.report_title=$TESTRUNNAME$STARTTIMEJM\

JM日志中的相关举报道具如下:

2021-12-11 20:53:56,036 DEBUG o.a.j.r.c.ReportGeneratorConfiguration: Report generator properties loading
2021-12-11 20:53:56,041 DEBUG o.a.j.r.c.ReportGeneratorConfiguration: Loading properties:
...
2021-12-11 20:53:56,091 DEBUG o.a.j.r.c.ReportGeneratorConfiguration: Use 'TG10_<REDACTED>_10T-20211211-2053' value for optional property 'jmeter.reportgenerator.report_title'
2021-12-11 20:53:56,091 INFO o.a.j.r.c.ReportGeneratorConfiguration: Property 'jmeter.reportgenerator.start_date' not found, using default value 'null' instead.
2021-12-11 20:53:56,091 INFO o.a.j.r.c.ReportGeneratorConfiguration: Property 'jmeter.reportgenerator.end_date' not found, using default value 'null' instead.
2021-12-11 20:53:56,091 INFO o.a.j.r.c.ReportGeneratorConfiguration: Property 'jmeter.reportgenerator.date_format' not found, using default value 'null' instead.
2021-12-11 20:53:56,112 INFO o.a.j.r.c.ReportGeneratorConfiguration: Will use date range start date: null, end date: null

在测试 运行 日志结束时,一切似乎都顺利进行,没有明显的错误。除了开始时间是 1970 年之外,该报告还不错。

2021-12-11 22:04:17,129 DEBUG o.a.j.r.d.ReportGenerator: Start report generation
2021-12-11 22:04:17,147 INFO o.a.j.r.p.NormalizerSampleConsumer: Using format, 'ms', to parse timeStamp field
2021-12-11 22:04:17,177 DEBUG o.a.j.r.d.ReportGenerator: Start samples processing
2021-12-11 22:04:18,554 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.AggregateConsumer#stopProducing(): beginDate produced 0 samples
2021-12-11 22:04:18,554 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.AggregateConsumer#stopProducing(): endDate produced 0 samples
2021-12-11 22:04:18,557 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.ApdexSummaryConsumer#stopProducing(): apdexSummary produced 0 samples
2021-12-11 22:04:18,557 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.RequestsSummaryConsumer#stopProducing(): requestsSummary produced 0 samples
2021-12-11 22:04:18,583 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.StatisticsSummaryConsumer#stopProducing(): statisticsSummary produced 0 samples
2021-12-11 22:04:18,585 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.Top5ErrorsBySamplerConsumer#stopProducing(): top5ErrorsBySampler produced 0 samples
2021-12-11 22:04:18,585 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.ErrorsSummaryConsumer#stopProducing(): errorsSummary produced 0 samples
2021-12-11 22:04:18,585 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.HitsPerSecondGraphConsumer#stopProducing(): hitsPerSecond produced 0 samples
2021-12-11 22:04:18,802 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.LatencyVSRequestGraphConsumer#stopProducing(): latencyVsRequest produced 0 samples
2021-12-11 22:04:18,804 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.SyntheticResponseTimeDistributionGraphConsumer#stopProducing(): syntheticResponseTimeDistribution produced 0 samples
2021-12-11 22:04:18,804 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.BytesThroughputGraphConsumer#stopProducing(): bytesThroughputOverTime produced 0 samples
2021-12-11 22:04:18,805 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.CodesPerSecondGraphConsumer#stopProducing(): codesPerSecond produced 0 samples
2021-12-11 22:04:19,016 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.ResponseTimeVSRequestGraphConsumer#stopProducing(): responseTimeVsRequest produced 0 samples
2021-12-11 22:04:19,018 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.FilterConsumer#stopProducing(): startIntervalControlerFilter produced 134253 samples
2021-12-11 22:04:19,018 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.TotalTPSGraphConsumer#stopProducing(): totalTPS produced 0 samples
2021-12-11 22:04:19,018 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.ActiveThreadsGraphConsumer#stopProducing(): activeThreadsOverTime produced 0 samples
2021-12-11 22:04:19,018 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.TimeVSThreadGraphConsumer#stopProducing(): timeVsThreads produced 0 samples
2021-12-11 22:04:19,022 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.ResponseTimeDistributionGraphConsumer#stopProducing(): responseTimeDistribution produced 0 samples
2021-12-11 22:04:19,022 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.TransactionsPerSecondGraphConsumer#stopProducing(): transactionsPerSecond produced 0 samples
2021-12-11 22:04:19,023 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.ResponseTimePercentilesGraphConsumer#stopProducing(): responseTimePercentiles produced 0 samples
2021-12-11 22:04:19,028 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.ResponseTimePercentilesOverTimeGraphConsumer#stopProducing(): responseTimePercentilesOverTime produced 0 samples
2021-12-11 22:04:19,038 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.ResponseTimeOverTimeGraphConsumer#stopProducing(): responseTimesOverTime produced 0 samples
2021-12-11 22:04:19,038 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.ConnectTimeOverTimeGraphConsumer#stopProducing(): connectTimeOverTime produced 0 samples
2021-12-11 22:04:19,038 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.graph.impl.LatencyOverTimeGraphConsumer#stopProducing(): latenciesOverTime produced 0 samples
2021-12-11 22:04:19,039 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.FilterConsumer#stopProducing(): nameFilter produced 287685 samples
2021-12-11 22:04:19,039 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.FilterConsumer#stopProducing(): dateRangeFilter produced 57537 samples
2021-12-11 22:04:19,039 INFO o.a.j.r.p.AbstractSampleConsumer: class org.apache.jmeter.report.processor.NormalizerSampleConsumer#stopProducing(): normalizer produced 19179 samples
2021-12-11 22:04:19,039 INFO o.a.j.r.p.CsvFileSampleSource: produce(): 19179 samples produced in 1s 862 ms on channel 0
2021-12-11 22:04:19,039 DEBUG o.a.j.r.d.ReportGenerator: End of samples processing
2021-12-11 22:04:19,039 DEBUG o.a.j.r.d.ReportGenerator: Start data exporting
2021-12-11 22:04:19,039 INFO o.a.j.r.d.ReportGenerator: Exporting data using exporter:'json' of className:'org.apache.jmeter.report.dashboard.JsonExporter'
2021-12-11 22:04:19,198 INFO o.a.j.r.d.JsonExporter: Found data for consumer statisticsSummary in context
2021-12-11 22:04:19,198 INFO o.a.j.r.d.JsonExporter: Creating statistics for overall
2021-12-11 22:04:19,198 DEBUG o.a.j.r.d.JsonExporter: Creating statistics for result data:MapResultData [map={data=ListResultData [items=[ValueResultData [value=Total], ValueResultData [value=19179], ValueResultData [value=306], ValueResultData [value=1.5954950727358048], ValueResultData [value=190.9874341727929], ValueResultData [value=0], ValueResultData [value=18125], ValueResultData [value=2.0], ValueResultData [value=123.0], ValueResultData [value=142.0], ValueResultData [value=4498.600000000002], ValueResultData [value=1.1699789539259888E-5], ValueResultData [value=9.498651393468875E-7], ValueResultData [value=6.08339376620762E-7]]], isController=ValueResultData [value=false]}]
2021-12-11 22:04:19,199 INFO o.a.j.r.d.JsonExporter: Creating statistics for other transactions
2021-12-11 22:04:19,199 DEBUG o.a.j.r.d.JsonExporter: Creating statistics for result data:MapResultData [map={data=ListResultData [items=[ValueResultData [value=[TG10TX3] <REDACTED>], ValueResultData [value=15000], ValueResultData [value=230], ValueResultData [value=1.5333333333333334], ValueResultData [value=1.8258000000000028], ValueResultData [value=0], ValueResultData [value=25], ValueResultData [value=2.0], ValueResultData [value=3.0], ValueResultData [value=3.0], ValueResultData [value=3.0], ValueResultData [value=9.150468903713162E-6], ValueResultData [value=1.7597972097375444E-8], ValueResultData [value=5.2793916292126333E-8]]], isController=ValueResultData [value=false]}]
2021-12-11 22:04:19,200 DEBUG o.a.j.r.d.JsonExporter: Creating statistics for result data:MapResultData [map={data=ListResultData [items=[ValueResultData [value=[TG10TX1] <REDACTED>], ValueResultData [value=514], ValueResultData [value=10], ValueResultData [value=1.9455252918287937], ValueResultData [value=171.44552529182874], ValueResultData [value=64], ValueResultData [value=3856], ValueResultData [value=98.0], ValueResultData [value=115.0], ValueResultData [value=127.0], ValueResultData [value=3220.4500000000044], ValueResultData [value=0.28588241444940937], ValueResultData [value=0.115374967601847], ValueResultData [value=0.015355012494841324]]], isController=ValueResultData [value=false]}]
2021-12-11 22:04:19,200 DEBUG o.a.j.r.d.JsonExporter: Creating statistics for result data:MapResultData [map={data=ListResultData [items=[ValueResultData [value=[TG10TX5] <REDACTED> Transaction], ValueResultData [value=500], ValueResultData [value=0], ValueResultData [value=0.0], ValueResultData [value=139.47400000000002], ValueResultData [value=75], ValueResultData [value=235], ValueResultData [value=142.0], ValueResultData [value=155.0], ValueResultData [value=160.95], ValueResultData [value=172.99], ValueResultData [value=0.2761083957384326], ValueResultData [value=0.11132615017784142], ValueResultData [value=0.05527560656872918]]], isController=ValueResultData [value=false]}]
2021-12-11 22:04:19,200 DEBUG o.a.j.r.d.JsonExporter: Creating statistics for result data:MapResultData [map={data=ListResultData [items=[ValueResultData [value=[TG10TX2] <REDACTED> Transaction], ValueResultData [value=665], ValueResultData [value=20], ValueResultData [value=3.007518796992481], ValueResultData [value=4774.747368421048], ValueResultData [value=65], ValueResultData [value=18125], ValueResultData [value=3917.0], ValueResultData [value=7708.199999999998], ValueResultData [value=10085.599999999995], ValueResultData [value=13883.720000000001], ValueResultData [value=0.36644448558908843], ValueResultData [value=0.15569962294102282], ValueResultData [value=0.049384120128216996]]], isController=ValueResultData [value=false]}]
2021-12-11 22:04:19,200 DEBUG o.a.j.r.d.JsonExporter: Creating statistics for result data:MapResultData [map={data=ListResultData [items=[ValueResultData [value=[TG10TX4] <REDACTED>], ValueResultData [value=2500], ValueResultData [value=46], ValueResultData [value=1.84], ValueResultData [value=120.9975999999999], ValueResultData [value=65], ValueResultData [value=540], ValueResultData [value=120.0], ValueResultData [value=132.0], ValueResultData [value=136.0], ValueResultData [value=147.0], ValueResultData [value=0.7160305785154739], ValueResultData [value=0.23962354889242957], ValueResultData [value=0.19858660576015094]]], isController=ValueResultData [value=false]}]
2021-12-11 22:04:19,200 INFO o.a.j.r.d.JsonExporter: Checking output folder
2021-12-11 22:04:19,200 INFO o.a.j.r.d.JsonExporter: Writing statistics JSON to <REDACTED>/statistics.json
2021-12-11 22:04:19,255 INFO o.a.j.r.d.ReportGenerator: Exporting data using exporter:'html' of className:'org.apache.jmeter.report.dashboard.HtmlTemplateExporter'
2021-12-11 22:04:19,257 DEBUG o.a.j.r.d.HtmlTemplateExporter: Start template processing
2021-12-11 22:04:19,258 INFO o.a.j.r.d.HtmlTemplateExporter: Will generate dashboard in folder: <REDACTED>
2021-12-11 22:04:19,434 INFO o.a.j.r.d.HtmlTemplateExporter: Report will be generated in: <REDACTED>, creating folder structure
2021-12-11 22:04:19,436 INFO o.a.j.r.d.TemplateVisitor: Copying folder from '/opt/apache-jmeter-5.4.1/bin/report-template' to '<REDACTED>', got message: <REDACTED>, found non empty folder with following content [<REDACTED>/statistics.json], will be ignored
2021-12-11 22:04:19,831 DEBUG o.a.j.r.d.HtmlTemplateExporter: End of template processing
2021-12-11 22:04:19,831 DEBUG o.a.j.r.d.ReportGenerator: End of data exporting
2021-12-11 22:04:19,831 DEBUG o.a.j.r.d.ReportGenerator: End of report generation

对接下来要深入研究的内容有什么建议吗?

这听起来像是 JMeter 或 WebSocket Sampler 插件中的错误,如果您将插件替换为其他采样器,例如 Debug Sampler or Dummy Sampler and the issue will be reproducible - raise an issue in JMeter Bugzilla

如果问题仅出现在 WebSocket Samplers 插件中,请在 plugin repository

中打开问题

同时,您可以通过设置 jmeter.reportgenerator.start_date 来覆盖测试开始日期,就像覆盖粒度和测试标题一样。