Skip to main content

log4j TCP SyslogAppender

The current SyslogAppender in log4j uses UDP to transmit the logs to syslog server. It potentially has risks of losing data and our ops guy was looking for a TCP based appender and ran into this http://www.rsyslog.com/tcp-syslog-rfc5424-log4j-appender/ and plugged it in. Then something weird happen as an appnode would keep running out of file handles and other app node ran into issue where all threads were stuck. The implementation at this link is buggy so I rewrote this and publishing here in case anyone is interested.

/**
 * TCP appender to syslog. This class uses a blocking queue with 10K message capacity and any requests beyond that would be rejected.
 * The append method from all caller threads inserts the message into blocking queue and there is a single background thread that logs to the syslog.
 * This complex queueing is introduced to relieve the user thread as soon as possible.
 *
 *
 */
public class Syslog4jTCPAppender extends Syslog4jAppender {
    private static final long serialVersionUID = 1L;

    private static ThreadLocal dateFormat = new ThreadLocal() {

        @Override
        protected SimpleDateFormat initialValue() {
            SimpleDateFormat df = new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ss.S'Z'");
            df.setTimeZone(TimeZone.getTimeZone("UTC"));
            return df;
        }

    };

    private Map facilitiesMap = new HashMap();

    private String localHost;

    private BlockingQueue blockingQueue = new ArrayBlockingQueue(10000);

    @Override
    public void activateOptions() {
        super.activateOptions();
        String[] facilities = { "KERN", "USER", "MAIL", "DAEMON", "AUTH", "SYSLOG", "LPR", "NEWS", "UUCP", "CRON", "AUTHPRIV",
                "FTP", "LOCAL0", "LOCAL1", "LOCAL2", "LOCAL3", "LOCAL4", "LOCAL5", "LOCAL6", "LOCAL7" };
        int[] facIntArray = { 0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 16, 17, 18, 19, 20, 21, 22, 23 };
        for (int i = 0; i < facilities.length; i++) {
            facilitiesMap.put(facilities[i], facIntArray[i]);
        }
        try {
            localHost = InetAddress.getLocalHost().getHostName();
        } catch (UnknownHostException e) {
            System.out.println("UnknownHostException" + e.getMessage());
            localHost = "Unknown";
        }
        SocketLoggerThread socketLoggerThread = new SocketLoggerThread();
        socketLoggerThread.setDaemon(true);
        socketLoggerThread.start();
    }

    @Override
    protected void append(LoggingEvent event) {
        int priority = calcPriority(event);
        String trace = super.layout.format(event);
        String newLineChar = "\n";
        String msg = trace.replaceAll(newLineChar, " ");
        Date dt = new Date();
        String dateString = dateFormat.get().format(dt);
        String message = "<" + priority + ">" + dateString + " " + localHost + " " + super.getIdent() + ": " + msg + "\n";
        blockingQueue.offer(message);
    }

    private int calcPriority(LoggingEvent event) {
        String facility = super.getFacility().toUpperCase();
        Integer facPriority = facilitiesMap.get(facility);
        if (facPriority == null) {
            facPriority = 1;
        }
        int level = event.getLevel().getSyslogEquivalent();
        int priority = facPriority * 8 + level;
        return priority;
    }

    private class SocketLoggerThread extends Thread {
        private Socket socket;

        private DataOutputStream os;
        private int counter;

        @Override
        public void run() {
            reinit();
            while (true) {
                try {
                    consume(blockingQueue.take());
                } catch (InterruptedException e) {
                    System.out.println("Syslog socket logger interrupted while waiting" + e.getMessage());
                } catch (Exception e) {
                    System.out.println("Unknown exception " + e.getMessage());
                }
            }
        }

        private void close() {
            try {
                if (os != null) {
                    os.close();
                }
            } catch (IOException e) {
                System.out.println("IOException closing os" + e.getMessage());
            }
            try {
                if (socket != null) {
                    socket.close();
                }
            } catch (IOException e) {
                System.out.println("IOException closing socket " + e.getMessage());
            }
        }

        private void reinit() {
            close();
            try {
                socket = new Socket(Syslog4jTCPAppender.super.getSyslogHost(), Integer.parseInt(Syslog4jTCPAppender.super.getPort()));
                os = new DataOutputStream(socket.getOutputStream());
            } catch (IOException e) {
                System.out.println("IOException opening socket" + e.getMessage());
            }
        }

        private void consume(String message) {
            try {
                counter++;
                os.writeUTF(message);
                if (counter % 5000 == 0) {
                    System.out.println("Reiniting syslog socket");
                    reinit();
                    counter = 0;
                }
            } catch (IOException e) {
                System.out.println("IOException writing message" + e.getMessage());
                reinit();
            }
        }
    }
}

Comments

  1. Thanks for the rewrite! Would you mind if we include this on the rsyslog side (and/or the tarball?)

    ReplyDelete
  2. Rainer please go ahead. I will github it soon when I get time but for now please go ahead and include it on the rsyslog side.

    fyi the code is live on 100+ nodes and so far I am not seeing any issues.

    ReplyDelete
  3. Kalpesh, did this code get onto github?

    ReplyDelete

Post a Comment

Popular posts from this blog

Killing a particular Tomcat thread

Update: This JSP does not work on a thread that is inside some native code.  On many occasions I had a thread stuck in JNI code and it wont work. Also in some cases thread.stop can cause jvm to hang. According to javadocs " This method is inherently unsafe. Stopping a thread with Thread.stop causes it to unlock all of the monitors that it has locked". I have used it only in some rare occasions where I wanted to avoid a system shutdown and in some cases we ended up doing system shutdown as jvm was hung so I had a 70-80% success with it.   -------------------------------------------------------------------------------------------------------------------------- We had an interesting requirement. A tomcat thread that was spawned from an ExecutorService ThreadPool had gone Rogue and was causing lots of disk churning issues. We cant bring down the production server as that would involve downtime. Killing this thread was harmless but how to kill it, t

Adding Jitter to cache layer

Thundering herd is an issue common to webapp that rely on heavy caching where if lots of items expire at the same time due to a server restart or temporal event, then suddenly lots of calls will go to database at same time. This can even bring down the database in extreme cases. I wont go into much detail but the app need to do two things solve this issue. 1) Add consistent hashing to cache layer : This way when a memcache server is added/removed from the pool, entire cache is not invalidated.  We use memcahe from both python and Java layer and I still have to find a consistent caching solution that is portable across both languages. hash_ring and spymemcached both use different points for server so need to read/test more. 2) Add a jitter to cache or randomise the expiry time: We expire long term cache  records every 8 hours after that key was added and short term cache expiry is 2 hours. As our customers usually comes to work in morning and access the cloud file server it can happe

Preparing for an interview after being employed 11 years at a startup

I would say I didn't prepared a hell lot but  I did 2 hours in night every day and every weekend around 8 hours for 2-3 months. I did 20-30 leetcode medium problems from this list https://leetcode.com/explore/interview/card/top-interview-questions-medium/.  I watched the first 12 videos of Lecture Videos | Introduction to Algorithms | Electrical Engineering and Computer Science | MIT OpenCourseWare I did this course https://www.educative.io/courses/grokking-the-system-design-interview I researched on topics from https://www.educative.io/courses/java-multithreading-for-senior-engineering-interviews and leetcode had around 10 multithreading questions so I did those I watched some 10-20 videos from this channel https://www.youtube.com/channel/UCn1XnDWhsLS5URXTi5wtFTA