3
 class LogWriter implements Runnable {

Socket client;

private static ThreadLocal<Date> date = new ThreadLocal<Date>() {
@Override
protected Date initialValue() {
    return new Date();
};
};

private static ThreadLocal<SimpleDateFormat> formatter = new ThreadLocal<SimpleDateFormat>() {
@Override
protected SimpleDateFormat initialValue() {
    return new SimpleDateFormat("yyyy_MM_dd");
};
};

public LogWriter(Socket client) {
this.client = client;
}

public void run() {
try {
    write(this.client.getInputStream(), new File(
        CentralizedLogging.logsDir + File.separator
            + client.getInetAddress().getHostName() + "_"
            + getFormattedDate() + ".log"));
    this.client.close();
} catch (Exception e) {
    try {
    e.printStackTrace();
    write(new ByteArrayInputStream(e.getMessage().getBytes()),
        new File(CentralizedLogging.logsDir + File.separator
            + "centralLoggingError.log"));
    } catch (IOException io) {

    }
}
}

  public synchronized void write(InputStream in, File file)
    throws IOException {
RandomAccessFile writer = new RandomAccessFile(file, "rw");
writer.seek(file.length()); // append the file content into existing if it not exist creating a new one.
writer.write(read(in));
writer.close();
}

public static byte[] read(InputStream in) throws IOException {
ByteArrayOutputStream out = new ByteArrayOutputStream();
int read = -1;
byte[] buffer = new byte[1024];
read = in.read(buffer);
do {
    out.write(buffer, 0, read);
} while((read = in.read(buffer)) > -1);
return out.toByteArray();
}

Main Method

   public static void main(String[] args) throws InterruptedException,
    IOException {
// CentralizedLogging centralLogServer = new CentralizedLogging(args[0],Integer.parseInt(args[1]));
// new Thread(centralLogServer).start();
long start = System.currentTimeMillis() + 1000 * 20 * 60;
while(start >= System.currentTimeMillis()) {
    Socket client = new Socket("bharathi-1397", 10000);
    OutputStream os = client.getOutputStream();
    DataOutputStream outToServer = new DataOutputStream(os);
    outToServer
        .write("Centralized Logging is working......".getBytes());
    client.close();
}
}

I am properly closed connection . But time_wait connections is increasing . I have take a snap shot from my terminal i am posted one portion of it . Is am missing any thing ?

 tcp6       0      0 127.0.0.1:46146         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:57645         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:47961         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:56716         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:49469         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:54078         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:51626         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:50143         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:59214         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:54192         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:53436         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:54547         127.0.0.1:10000         TIME_WAIT   -               
 tcp6       0      0 127.0.0.1:55032         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:51273         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:48381         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:47532         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:56811         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:55293         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:56664         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:49242         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:51225         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:59265         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:59378         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:47997         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:47955         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:59453         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:48092         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:52462         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:59579         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:54921         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:55675         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:51140         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:57321         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:51656         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:54740         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:53600         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:59862         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:54766         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:59062         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:55702         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:50942         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:53732         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:52757         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:56430         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:49179         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:48689         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:53313         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:51161         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:57033         127.0.0.1:10000         TIME_WAIT   -               
tcp6       0      0 127.0.0.1:58607         127.0.0.1:10000         TIME_WAIT   - 

It causes any problem to my server ?. What is the reason for this ? .

kannanrbk
  • 6,964
  • 13
  • 53
  • 94

1 Answers1

3

I am properly closing connection but time_wait connections is increasing. Am I missing anything?

The TIME_WAIT is used by the kernel to make sure that your TCP stream does not re-use a port that may still have packets being sent to it from the remote side. The TIME_WAIT time is generally set to double the packets maximum age based on network settings.

If you are getting a number of new connections, then you will see the number of ports in TIME_WAIT increase but at some point it should stabilize unless the connection rate is also increasing. One thing to do is to grep for all of the TIME_WAIT lines, sort them and see if the port numbers are changing. If new ports are being added and old ones falling off then all is fine.

One thing to try is to make sure that your client is initiating the close() call. That would leave the TIME_WAIT on the client and not on the server. See this excellent page about TCP and the implications of TIME_WAIT on the server.

Since it seems like your server is sending a file to the client (if I'm reading your code correctly), you should consider changing your protocol to something like the following. That would cause the client to close first so most of the TIME_WAITs will be on each of the clients.

  1. server sends the length of the file first
  2. server sends the file
  3. client reads the length
  4. client reads the file bytes
  5. client sends "got it"
  6. client closes
  7. server reads the client's "got it" message
  8. server closes

Did you see the bit about having the client make the close() first @kannan?  If the server is sending a file then I would have it send the file and then wait for the client to send a "got it" message.  The client can then read the file, read an EOF marker, send the "got it" and then close immediately.

Also, as an aside, you should be using try ... finally patterns in your code. Something like:

public void run() {
    try {
        write(this.client.getInputStream(), new File(
            CentralizedLogging.logsDir + File.separator
            + client.getInetAddress().getHostName() + "_"
            + getFormattedDate() + ".log"));
    } catch (Exception e) {
        try {
            e.printStackTrace();
            write(new ByteArrayInputStream(e.getMessage().getBytes()),
                new File(CentralizedLogging.logsDir + File.separator
                + "centralLoggingError.log"));
        } catch (IOException io) {
        }
    } finally {
        // always close in the finally
        this.client.close();
    }
}
Gray
  • 115,027
  • 24
  • 293
  • 354
  • Unique TimeWait Connections netstat -anp | grep 10000 | awk '{print }' | cut -d ':' -f2 | sort -u | wc -l (Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.) 20730 Total Time Wait Connections netstat -anp | grep 10000 | awk '{print }' | cut -d ':' -f2 | wc -l (Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.) 20730 Is this any problem If my client's are increasing ? . Still I am missing anything ? . Is this fine ? – kannanrbk May 23 '12 at 19:28
  • Save that in a file and then do it again in 30 seconds and save that to a file. Then diff the files. Make sure that the `TIME_WAIT` lines are falling off and getting replaced. If they are never going away then you might need to tweak the network settings in your kernel. – Gray May 23 '12 at 19:29
  • I've added a section to my answer @kannan to show how you can change your client/server to have the `TIME_WAIT` be incurred by the client not the server. – Gray May 23 '12 at 20:28
  • Thank you . I am not sending any files to server just sending 20 or 30 bytes content only . Socket client = new Socket("bharathi-1397", 10000); OutputStream os = client.getOutputStream(); DataOutputStream outToServer = new DataOutputStream(os); outToServer .write("Centralized Logging is working......".getBytes()); client.close(); And i also follows your try catch finally block in my code . – kannanrbk May 23 '12 at 21:03
  • It is to make sure you don't reuse a *port* that may still have *packets* being sent to it from the other side. *Ports* are in TIME_WAIT, not sockets, and `netstat` shows port numbers, not sockets. Present statements are nonsense. The basic technique to ensure the client closes doesn't need a final 'ACK' from the client: it is exactly the same as for connection-pooling: write the server so as to handle multiple requests per fonnection, and use a connection pool at the client that closes idle connections. That way the server will be the end that receives the first FIN. – user207421 Feb 13 '17 at 00:08
  • Sockets to ports. Duh. Fixed. Thanks @EJP. Don't understand about the "present statements". – Gray Feb 13 '17 at 16:07