File I/O from threads

Hi, I was writing a quick Relay class and ran into a problem.
Objects of this class act between two ports and log every TCP/IP that is
sent between those ports - according to a specific protocol (in this
simple example the first 8 characters contain the length of the data
that will follow)

These are the important methods of the class. All objects are local to
the object and not shared between other objects.

  def start
    @server = TCPServer.new(l_h, l_p)
    @client = TCPSocket.new(r_h, r_p)

    loop do
      Thread.start(@server.accept) do |s|
          # handshake(s)
          client_to_server(s)
          server_to_client(s)
        end
    end
  end

  def client_to_server(s)
    Thread.new do
      loop do
        len = @client.recv(8)
        msg = @client.recv(len.to_i)
        @logfile.puts("Received " + msg)
        s.write(len)
        s.write(msg)
      end
    end
  end

  def server_to_client(s)
    Thread.new do
      loop do
        len = s.recv(8)
        msg = s.recv(len.to_i)
        @logfile.puts("Sent " + msg)
        @client.write(len)
        @client.write(msg)
      end
    end
  end

My problem is that the file operations (@logfile.puts) are not performed
immediately. When I check the file while communication is passing by, it
is incomplete, sometimes even empty. Only when I kill the connection
contained in @server.accept is the file properly flushed and is all
traffic put into it.
I don't understand why this happens. Why does @logfile.puts not happen
immediately while @client.write and s.write do?
I can't see why this would have anything to do with thread safety.

Putting a mutex lock/unlock around the file operation didn't really do
anything (I didn't really expect that to work either)

Can anybody tell me what is happening here?

···

--
Posted via http://www.ruby-forum.com/.

You see the effect of IO buffering which indeed does not have anything to do with multi threading. You basically have two options to remedy that

1. use @client.sync = true for automatic flushing after every write operation

2. manually invoke #flush

Independent from that you should take measures to make writing to the logfile thread safe. One option would be to have a reserved writer thread which pulls log messages from a Queue and writes them to the file.

Another alternative is your approach (synchronization).

Kind regards

  robert

···

On 28.04.2009 17:19, Maarten Mortier wrote:

Hi, I was writing a quick Relay class and ran into a problem.
Objects of this class act between two ports and log every TCP/IP that is
sent between those ports - according to a specific protocol (in this
simple example the first 8 characters contain the length of the data
that will follow)

These are the important methods of the class. All objects are local to
the object and not shared between other objects.

  def start
    @server = TCPServer.new(l_h, l_p)
    @client = TCPSocket.new(r_h, r_p)

    loop do
      Thread.start(@server.accept) do |s|
          # handshake(s)
          client_to_server(s)
          server_to_client(s)
        end
    end
  end

  def client_to_server(s)
    Thread.new do
      loop do
        len = @client.recv(8)
        msg = @client.recv(len.to_i)
        @logfile.puts("Received " + msg)
        s.write(len)
        s.write(msg)
      end
    end
  end

  def server_to_client(s)
    Thread.new do
      loop do
        len = s.recv(8)
        msg = s.recv(len.to_i)
        @logfile.puts("Sent " + msg)
        @client.write(len)
        @client.write(msg)
      end
    end
  end

My problem is that the file operations (@logfile.puts) are not performed
immediately. When I check the file while communication is passing by, it
is incomplete, sometimes even empty. Only when I kill the connection
contained in @server.accept is the file properly flushed and is all
traffic put into it.
I don't understand why this happens. Why does @logfile.puts not happen
immediately while @client.write and s.write do?
I can't see why this would have anything to do with thread safety.

Putting a mutex lock/unlock around the file operation didn't really do
anything (I didn't really expect that to work either)

Can anybody tell me what is happening here?

Robert Klemme wrote:

You see the effect of IO buffering

Thanks!

Maarten

···

--
Posted via http://www.ruby-forum.com/\.