log4j - SocketAppender - java.io.EOFException

[yann luppo]

I'm currently looking into doing asynchronous remote logging with log4j.
I've successfully implemented my AsyncAppender and tested it with the console appender, and now I'm trying to implement it with the SocketAppender, but I'm getting this error in the server log file:

 INFO (10 Dec 2008 10:29:11,303) [main] (SimpleSocketServer.java:60) - Listening on port 56564
 INFO (10 Dec 2008 10:29:11,318) [main] (SimpleSocketServer.java:63) - Waiting to accept a new client.
 INFO (10 Dec 2008 10:29:14,631) [main] (SimpleSocketServer.java:65) - Connected to client at /127.0.0.1
 INFO (10 Dec 2008 10:29:14,631) [main] (SimpleSocketServer.java:66) - Starting new socket node.
 INFO (10 Dec 2008 10:29:14,631) [main] (SimpleSocketServer.java:63) - Waiting to accept a new client.
 INFO (10 Dec 2008 10:29:14,647) [Thread-0] (SocketNode.java:89) - Caught java.io.EOFException closing conneciton.

Here is my config file on the client:

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
  <appender name="async" class="org.apache.log4j.AsyncAppender">
  <appender-ref ref="console" />
  <appender-ref ref="socket" />
  <param name="Blocking" value="false"/>
  <param name="bufferSize" value="256"/>
  </appender>
  
  <appender name="socket" class="org.apache.log4j.net.SocketAppender">
  <param name="Port" value="56564"/>
  <param name="RemoteHost" value="localhost"/>
  <param name="ReconnectionDelay" value="5000"/>
  <param name="LocationInfo" value="true"/>
  </appender>
 
  <appender name="console" class="org.apache.log4j.ConsoleAppender"> 
    <param name="Target" value="System.out"/> 
    <layout class="org.apache.log4j.PatternLayout"> 
      <param name="ConversionPattern" value="%-5p %c{1} - %m%n"/> 
    </layout> 
  </appender>
  
  <logger name="async.main.MainClass">
  <param name="level" value="DEBUG"/>
  </logger>
   
  <root> 
    <param name="level" value="DEBUG"/>
    <appender-ref ref="async" /> 
  </root>
  
</log4j:configuration>

Here is my client test code:

package async.main;
 
import org.apache.log4j.AsyncAppender;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
import org.apache.log4j.net.SocketAppender;
import org.apache.log4j.xml.DOMConfigurator;
 
public class MainClass {
 
private final static Logger log = Logger.getLogger(MainClass.class);
 
public static void main(String[] args) {
DOMConfigurator.configure("bin/configuration/log4j.xml");
try
{
log.info("hello world");
testLogger();
}
finally
{
AsyncAppender asyncAppender = (AsyncAppender)Logger.getRootLogger().getAppender("async");
if (asyncAppender != null)
{
SocketAppender socketAppender = (SocketAppender)asyncAppender.getAppender("socket");
if (socketAppender != null)
{
socketAppender.close();
LogManager.shutdown();
}
}
}
}

private static void testLogger()
{
log.error("This is a really bad error");
}
 
}

Now on the server side I'm running a very simple console app that's really just instanciating the log4j SimpleSocketServer implementation:

package asyncServer;
 
import org.apache.log4j.net.SimpleSocketServer;
 
public class MainClass {
 
public static void main(String[] args) {
try
{
String[] arguments = {"56564", "bin/configuration/server.xml"};
SimpleSocketServer.main(arguments);
}
catch (Exception ex)
{

}
}
}

With the following config file associated to it:

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
<appender name="rolling" class="org.apache.log4j.RollingFileAppender">
    <layout class="org.apache.log4j.PatternLayout">
      <param name="ConversionPattern" value="%5p (%d{DATE}) [%t] (%F:%L) - %m%n"/>
    </layout>
    <param name="File" value="bin/logs/async.log"/>
    <param name="MaxFileSize" value="10KB"/>
    <param name="MaxBackupIndex" value="5"/>
  </appender>
  
  <root> 
    <param name="level" value="DEBUG"/>
    <appender-ref ref="rolling" /> 
  </root>
</log4j:configuration>

Since log4j is very verbose, from the Eclipse console I've been able to verify that both config files, client and server, get picked up correctly.

I did find something interesting Googling around:

SimpleSocketServer BufferedIO issue

But that didn't help very much. Tried the suggestion and still getting the same error message.

Anyone successfully implemented AsyncAppender + SocketAppender with SimpleSocketServer by any chance?

Any idea if this is a "user" error or a problem with the SimpleSocketServer implementation? Any other SocketNode server implementation I could try out there?

[yann luppo]

I still couldn't find anything on the web and no one actually replied to my post, so I'm guessing either it's a bug, or no one is using the SocketAppender w/ the SimpleSocketServer (unlikely but who knows...)

Anyway I've replaced the SocketAppender with the SocketHubAppender in my AsyncAppender, and it seems to work. The only thing is it actually works backward... The machine with the AsyncAppender and the SocketHubAppender now buffers all the logs on a port and if something connects on that port then it gets the logs, if nothing connects the older logs are pushed out of the buffer.

In a nutshell my client app (which really behaves as a server now) has the following config file:

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
  <appender name="async" class="org.apache.log4j.AsyncAppender">
  <appender-ref ref="socketHub" />
  <param name="Blocking" value="false"/>
  <param name="bufferSize" value="256"/>
  </appender>
  
  <appender name="socketHub" class="org.apache.log4j.net.SocketHubAppender">
  <param name="Port" value="56564"/>
  </appender>
    
  <logger name="async.main.MainClass">
  <param name="level" value="DEBUG"/>
  </logger>
   
  <root> 
    <param name="level" value="DEBUG"/>
    <appender-ref ref="async" /> 
  </root>
  
</log4j:configuration>

My client code is very simple:

public static void main(String[] args) throws InterruptedException {
DOMConfigurator.configure("bin/configuration/log4j.xml");

while (true)
{
for (int i = 0; i < 100; i++)
log.info("hello world");
 
Thread.sleep(1000);
}
}

My server is barebone for now. I'm guessing you could implement log4j to it pretty easily, the same way it's done for the client, but for what we need to do, we might just go custom from the raw data in the LoggingEvent object. The code looks like this:

public static void main(String[] args) {
try
{
Socket socket = null;
socket = new Socket("localhost", 56564);

while (true)
{
try
{


ObjectInputStream ois = new ObjectInputStream(new
BufferedInputStream(socket.getInputStream()));

LoggingEvent incomingEvent = (LoggingEvent) ois.readObject();
System.out.println("My log message was: " + incomingEvent.getMessage());
System.out.println("Its level was: " + incomingEvent.level.toString());


}
finally
{
if (socket != null)
socket.close();

socket = null;
}
}
}
catch (Exception ex)
{
System.out.println("An error occured: " + ex.getMessage());

}
}

Hope this helps whoever is encountering the same type of issues, or like me has spent way too much time trying to figure out how to use the SocketAppender or the SocketHubAppender.

Looking forward to test the SocketAppender in Log4j 2.0.

Cheers,
Yann

[Martijn Verburg]

Thanks for posting a solution Yann. I'll confess I've never tried doing that with Log4J so I couldn't help