Timestamps in CSV file could be corrupted due to sharing a SimpleDateFormatter across threads

[asfimport]

eric.markowitz (Bug 60830): The java.text.SimpleDateFormatter class is not thread safe, but jmeter reuses a SimpleDateFormatter instance across threads. As a result, the saved timestamp is sometimes incorrect. Here is the stack trace of one of the offending locations:

org.apache.jmeter.save.CSVSaveService.resultToDelimitedString(CSVSaveService.java:868) org.apache.jmeter.save.CSVSaveService.resultToDelimitedString(CSVSaveService.java:784) org.apache.jmeter.reporters.ResultCollector.sampleOccurred(ResultCollector.java:559) org.apache.jmeter.threads.ListenerNotifier.notifyListeners(ListenerNotifier.java:67) org.apache.jmeter.threads.JMeterThread.notifyListeners(JMeterThread.java:819) org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:493) org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:410) org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:241) java.lang.Thread.run(Thread.java:745)

Severity: blocker OS: All

Duplicates:

• https://github.com/apache/jmeter/issues/4317

[asfimport]

@pmouawad (migrated from Bugzilla): (In reply to eric.markowitz from comment 0)

The java.text.SimpleDateFormatter class is not thread safe, but jmeter reuses a SimpleDateFormatter instance across threads. As a result, the saved timestamp is sometimes incorrect. Here is the stack trace of one of the offending locations:

org.apache.jmeter.save.CSVSaveService.resultToDelimitedString(CSVSaveService. java:868) org.apache.jmeter.save.CSVSaveService.resultToDelimitedString(CSVSaveService. java:784) org.apache.jmeter.reporters.ResultCollector.sampleOccurred(ResultCollector. java:559) org.apache.jmeter.threads.ListenerNotifier.notifyListeners(ListenerNotifier. java:67) org.apache.jmeter.threads.JMeterThread.notifyListeners(JMeterThread.java:819) org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread. java:493) org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:410) org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:241) java.lang.Thread.run(Thread.java:745)

Hello Eric, Thanks for report, but where is the SimpleDateFormatter you mention ? What version of JMeter are you using ?

Thanks

[asfimport]

eric.markowitz (migrated from Bugzilla): I omitted some stack frames previously. Here is the full stack:

    at java.text.SimpleDateFormat.format(SimpleDateFormat.java:971)
    at java.text.SimpleDateFormat.format(SimpleDateFormat.java:935)
    at java.text.DateFormat.format(DateFormat.java:345)
    at org.apache.jmeter.save.CSVSaveService.resultToDelimitedString(CSVSaveService.java:868)
    at org.apache.jmeter.save.CSVSaveService.resultToDelimitedString(CSVSaveService.java:784)
    at org.apache.jmeter.reporters.ResultCollector.sampleOccurred(ResultCollector.java:559)
    at org.apache.jmeter.threads.ListenerNotifier.notifyListeners(ListenerNotifier.java:67)
    at org.apache.jmeter.threads.JMeterThread.notifyListeners(JMeterThread.java:819)
    at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:493)
    at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:410)
    at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:241)
    at java.lang.Thread.run(Thread.java:745)

I noticed the problem in jmeter version3.

[asfimport]

@pmouawad (migrated from Bugzilla): Hi Team, Could we use DateTimeFormatter to fix this issue ?

Instanciating a SimpleDateFormat for each call might be overkill. Using ThreadLocal SimpleDateFormat is not simple here

[asfimport]

@pmouawad (migrated from Bugzilla): Created attachment BUG_60830.patch: Patch that does not handle setLenient

BUG_60830.patch

````diff Index: src/core/org/apache/jmeter/samplers/SampleSaveConfiguration.java =================================================================== --- src/core/org/apache/jmeter/samplers/SampleSaveConfiguration.java (revision 1785890) +++ src/core/org/apache/jmeter/samplers/SampleSaveConfiguration.java (working copy) @@ -31,6 +31,7 @@ import java.util.Properties; import org.apache.commons.lang3.CharUtils; +import org.apache.commons.lang3.time.FastDateFormat; import org.apache.jmeter.save.CSVSaveService; import org.apache.jmeter.testelement.TestPlan; import org.apache.jmeter.util.JMeterUtils; @@ -276,7 +277,7 @@ private static final boolean SAMPLE_COUNT; - private static final DateFormat DATE_FORMATTER; + private static final FastDateFormat DATE_FORMATTER; /** * The string used to separate fields when stored to disk, for example, the @@ -353,7 +354,7 @@ // Prepare for a pretty date // FIXME Can TIMESTAMP_FORMAT be null ? it does not appear to me . if (!PRINT_MILLISECONDS && !NONE.equalsIgnoreCase(TIMESTAMP_FORMAT) && (TIMESTAMP_FORMAT != null)) { - DATE_FORMATTER = new SimpleDateFormat(TIMESTAMP_FORMAT); + DATE_FORMATTER = FastDateFormat.getInstance(TIMESTAMP_FORMAT); } else { DATE_FORMATTER = null; } @@ -441,7 +442,7 @@ private boolean printMilliseconds = PRINT_MILLISECONDS; /** A formatter for the time stamp. */ - private transient DateFormat formatter = DATE_FORMATTER; + private transient FastDateFormat formatter = DATE_FORMATTER; /* Make transient as we don't want to save the SimpleDataFormat class * Also, there's currently no way to change the value via the GUI, so changing it * later means editting the JMX, or recreating the Listener. @@ -581,7 +582,7 @@ try { SampleSaveConfiguration clone = (SampleSaveConfiguration)super.clone(); if(this.formatter != null) { - clone.formatter = (SimpleDateFormat)this.formatter.clone(); + clone.formatter = (FastDateFormat)this.formatter.clone(); } return clone; } @@ -907,13 +908,14 @@ ///////////////// End of standard field accessors ///////////////////// + /** * Intended for use by CsvSaveService (and test cases) * @param fmt * format of the date to be saved. If null * milliseconds since epoch will be printed */ - public void setFormatter(DateFormat fmt){ + public void setFastDateFormater(FastDateFormat fmt){ printMilliseconds = fmt == null; // maintain relationship formatter = fmt; } @@ -922,7 +924,7 @@ return printMilliseconds; } - public DateFormat formatter() { + public FastDateFormat threadSafeFormatter() { return formatter; } Index: src/core/org/apache/jmeter/save/CSVSaveService.java =================================================================== --- src/core/org/apache/jmeter/save/CSVSaveService.java (revision 1785890) +++ src/core/org/apache/jmeter/save/CSVSaveService.java (working copy) @@ -30,7 +30,6 @@ import java.io.Writer; import java.nio.charset.StandardCharsets; import java.text.ParseException; -import java.text.SimpleDateFormat; import java.util.ArrayList; import java.util.Date; import java.util.List; @@ -40,6 +39,7 @@ import org.apache.commons.collections.map.LinkedMap; import org.apache.commons.lang3.CharUtils; import org.apache.commons.lang3.StringUtils; +import org.apache.commons.lang3.time.FastDateFormat; import org.apache.jmeter.assertions.AssertionResult; import org.apache.jmeter.reporters.ResultCollector; import org.apache.jmeter.samplers.SampleEvent; @@ -214,15 +214,14 @@ log.warn("Cannot parse timestamp: '{}'", text); boolean foundMatch = false; for(String fmt : DATE_FORMAT_STRINGS) { - SimpleDateFormat dateFormat = new SimpleDateFormat(fmt); - dateFormat.setLenient(false); + FastDateFormat dateFormat = FastDateFormat.getInstance(fmt); try { Date stamp = dateFormat.parse(text); timeStamp = stamp.getTime(); // method is only ever called from one thread at a time // so it's OK to use a static DateFormat log.warn("Setting date format to: {}", fmt); - saveConfig.setFormatter(dateFormat); + saveConfig.setFastDateFormater(dateFormat); foundMatch = true; break; } catch (ParseException pe) { @@ -233,8 +232,8 @@ throw new ParseException("No date-time format found matching "+text,-1); } } - } else if (saveConfig.formatter() != null) { - Date stamp = saveConfig.formatter().parse(text); + } else if (saveConfig.threadSafeFormatter() != null) { + Date stamp = saveConfig.threadSafeFormatter().parse(text); timeStamp = stamp.getTime(); } else { // can this happen? final String msg = "Unknown timestamp format"; @@ -802,8 +801,8 @@ if (saveConfig.saveTimestamp()) { if (saveConfig.printMilliseconds()) { text.append(sample.getTimeStamp()); - } else if (saveConfig.formatter() != null) { - String stamp = saveConfig.formatter().format( + } else if (saveConfig.threadSafeFormatter() != null) { + String stamp = saveConfig.threadSafeFormatter().format( new Date(sample.getTimeStamp())); text.append(stamp); } Index: test/src/org/apache/jmeter/samplers/TestSampleSaveConfiguration.java =================================================================== --- test/src/org/apache/jmeter/samplers/TestSampleSaveConfiguration.java (revision 1785887) +++ test/src/org/apache/jmeter/samplers/TestSampleSaveConfiguration.java (working copy) @@ -25,10 +25,10 @@ import static org.junit.Assert.assertTrue; import java.lang.reflect.Method; -import java.text.SimpleDateFormat; import java.util.ArrayList; import java.util.List; +import org.apache.commons.lang3.time.FastDateFormat; import org.apache.jmeter.junit.JMeterTestCase; import org.junit.Test; @@ -136,13 +136,13 @@ assertEquals("Hash codes should be equal",a.hashCode(), b.hashCode()); assertTrue("Objects should be equal",a.equals(b)); assertTrue("Objects should be equal",b.equals(a)); - a.setFormatter(null); - b.setFormatter(null); + b.setFastDateFormater(null); + b.setFastDateFormater(null); assertEquals("Hash codes should be equal",a.hashCode(), b.hashCode()); assertTrue("Objects should be equal",a.equals(b)); assertTrue("Objects should be equal",b.equals(a)); - a.setFormatter(new SimpleDateFormat()); - b.setFormatter(new SimpleDateFormat()); + b.setFastDateFormater(FastDateFormat.getInstance()); + b.setFastDateFormater(FastDateFormat.getInstance()); assertEquals("Hash codes should be equal",a.hashCode(), b.hashCode()); assertTrue("Objects should be equal",a.equals(b)); assertTrue("Objects should be equal",b.equals(a)); ````

[asfimport]

eric.markowitz (migrated from Bugzilla): I don't think https://github.com/apache/jmeter/issues/4317 is a duplicate. https://github.com/apache/jmeter/issues/4317 refers to a corruption of the CSV file, while this bug referes to incorrect timestamps written to the CSV file.

[asfimport]

@pmouawad (migrated from Bugzilla): (In reply to eric.markowitz from comment 6)

I don't think https://github.com/apache/jmeter/issues/4317 is a duplicate. https://github.com/apache/jmeter/issues/4317 refers to a corruption of the CSV file, while this bug referes to incorrect timestamps written to the CSV file.

Hi, The other bug is Invalid in fact. See related discussion. But if there is a corruption, it's in the issue your raised.

Regards

[asfimport]

@pmouawad (migrated from Bugzilla): Hi, Any feedback on patch ? Or alternative solution ?

I think we need to fix this bug before 3.2 . Thanks

[asfimport]

@pmouawad (migrated from Bugzilla): Author: pmouawad Date: Sat Mar 18 10:12:31 2017 New Revision: 1787542

URL: http://svn.apache.org/viewvc?rev=1787542&view=rev Log: https://github.com/apache/jmeter/issues/4322 - Timestamps in CSV file could be corrupted due to sharing a SimpleDateFormatter across threads https://github.com/apache/jmeter/issues/4322

Modified: jmeter/trunk/src/core/org/apache/jmeter/samplers/SampleSaveConfiguration.java jmeter/trunk/src/core/org/apache/jmeter/save/CSVSaveService.java jmeter/trunk/test/src/org/apache/jmeter/samplers/TestSampleSaveConfiguration.java jmeter/trunk/xdocs/changes.xml

[asfimport]

@pmouawad (migrated from Bugzilla): Author: pmouawad Date: Sun Mar 26 20:00:59 2017 New Revision: 1788774

URL: http://svn.apache.org/viewvc?rev=1788774&view=rev Log: https://github.com/apache/jmeter/issues/4322 Timestamps in CSV file could be corrupted due to sharing a SimpleDateFormatter across threads https://github.com/apache/jmeter/issues/4322

Modified: jmeter/trunk/src/core/org/apache/jmeter/samplers/SampleSaveConfiguration.java