| Summary: | ThrowableInformation.getThrowableStringRep() can return null lines. | ||
|---|---|---|---|
| Product: | Log4j - Now in Jira | Reporter: | Ulrich Voigt <ulrich.voigt> |
| Component: | Appender | Assignee: | log4j-dev <log4j-dev> |
| Status: | RESOLVED FIXED | ||
| Severity: | normal | CC: | bojan.kalan, borysb, greg.jos |
| Priority: | P2 | Keywords: | PatchAvailable |
| Version: | 1.2 | ||
| Target Milestone: | --- | ||
| Hardware: | Other | ||
| OS: | other | ||
|
Description
Ulrich Voigt
2007-12-06 05:47:05 UTC
I forgot to mention that the problem occured with version 1.2.15. We had a similar problem.
The problem is that we use an AsynchAppender and a SocketAppender for logging.
Because of how AsynchAppender works, it is possible that
ThrowableInformation.getThrowableStrRep() runs on one LoggingEvent at the same time.
public
String[] getThrowableStrRep() {
if(rep != null) {
return (String[]) rep.clone();
} else {
StringWriter sw = new StringWriter();
PrintWriter pw = new PrintWriter(sw);
throwable.printStackTrace(pw);
pw.flush();
LineNumberReader reader = new LineNumberReader(
new StringReader(sw.toString()));
ArrayList lines = new ArrayList();
try {
String line = reader.readLine();
while(line != null) {
lines.add(line);
line = reader.readLine();
}
} catch(IOException ex) {
lines.add(ex.toString());
}
rep = new String[lines.size()];
lines.toArray(rep);
}
return rep;
}
The problem is with ThrowableInformation.rep.
If the first concurrent thread gets only to rep = new String[lines.size()];
and then the next concurrent thread gets to if(rep != null),
then only rep.clone(); is returned with an empty array.
Then later concurrent thread #1 will fill up the array but that's already late
for the another concurrent thread.
I think in this case the solution would be either to
a) synchronize on ThrowableInformation.getThrowableStrRep() or
b) modify
rep = new String[lines.size()];
lines.toArray(rep);
in method with
String[] tempRep = new String[lines.size()];
lines.toArray(tempRep);
rep = tempRep;
The solution looks good to me. I prefer solution b) because I cannot estimate the overall impacts of solution a). My problem is that the bug occurs very rarely. I got only two cases in 2 months. So I could not say for sure that the patch fixes the problem :-( Anyhow: Can someone please commit the patch? Changed summary of bug since bug is not specific to RollingFileAppender. Changes committed in rev 612863. In addition to the synchronization issue, there was an isolation issue. On every call except the first, the cached string representation was cloned before being returned. However, if you got the first call, you could "rewrite" the string representation by modifying the returned value. ThrowableInformationTest.testIsolation would fail with log4j 1.2.15. Whatever it did, it should have been consistent. Either everyone should be able to rewrite or no one should be able to rewrite. *** Bug 23019 has been marked as a duplicate of this bug. *** *** Bug 45825 has been marked as a duplicate of this bug. *** Is there any workaround to this and/or an ETA for 1.2.16 ? |