Store remote IP adress in connection struct (#718)

The remote IP is used in access logging but if the connection is closed
at the time of creating the log message it is not possible to fetch it.
(In fact, it currently segfaults, but will error in future Julia versions,
see JuliaLang/julia#40993). With this patch the remote IP is stored in
the Connection struct. This should not cost anything extras since the call
to Sockets.getpeername(...) is already there for storing the remote port.

src/ConnectionPool.jl

@@ -66,7 +66,8 @@ Fields:
 - `port::String`, exactly as specified in the URI (i.e. may be empty).
 - `pipeline_limit`, number of requests to send before waiting for responses.
 - `idle_timeout`, No. of seconds to maintain connection after last transaction.
-- `peerport`, remote TCP port number (used for debug messages).
+- `peerip`, remote IP adress (used for debug/log messages).
+- `peerport`, remote TCP port number (used for debug/log messages).
 - `localport`, local TCP port number (used for debug messages).
 - `io::T`, the `TCPSocket` or `SSLContext.
 - `clientconnection::Bool`, whether the Connection was created from client code (as opposed to server code)
@@ -88,7 +89,8 @@ mutable struct Connection{T <: IO}
     pipeline_limit::Int
     idle_timeout::Int
     require_ssl_verification::Bool
-    peerport::UInt16 # debug only
+    peerip::IPAddr # for debugging/logging
+    peerport::UInt16 # for debugging/logging
     localport::UInt16 # debug only
     io::T
     clientconnection::Bool
@@ -143,7 +145,7 @@ Connection(host::AbstractString, port::AbstractString,
     Connection{T}(host, port,
                   pipeline_limit, idle_timeout,
                   require_ssl_verification,
-                  peerport(io), localport(io),
+                  safe_getpeername(io)..., localport(io),
                   io, client, PipeBuffer(), Threads.Atomic{Int}(0),
                   0, Cond(), false,
                   0, Cond(), false,

src/IOExtras.jl

@@ -12,7 +12,7 @@ using MbedTLS: MbedException
 
 export bytes, ByteView, nobytes, CodeUnits, IOError, isioerror,
        startwrite, closewrite, startread, closeread,
-       tcpsocket, localport, peerport
+       tcpsocket, localport, safe_getpeername
 
 
 """
@@ -85,11 +85,15 @@ localport(io) = try !isopen(tcpsocket(io)) ? 0 :
                     0
                 end
 
-peerport(io) = try !isopen(tcpsocket(io)) ? 0 :
-                  Sockets.getpeername(tcpsocket(io))[2]
-               catch
-                   0
-               end
+function safe_getpeername(io)
+    try
+        if isopen(tcpsocket(io))
+            return Sockets.getpeername(tcpsocket(io))
+        end
+    catch
+    end
+    return IPv4(0), UInt16(0)
+end
 
 
 const ByteView = typeof(view(UInt8[], 1:0))

src/access_log.jl

@@ -65,9 +65,9 @@ function symbol_mapping(s::Symbol)
         hdr = replace(String(m[1]), '_' => '-')
         :(HTTP.header(http.message.response, $hdr, "-"))
     elseif s === :remote_addr
-        :(Sockets.getpeername(http)[1])
+        :(http.stream.c.peerip)
     elseif s === :remote_port
-        :(Sockets.getpeername(http)[2])
+        :(http.stream.c.peerport)
     elseif s === :remote_user
         :("-") # TODO: find from Basic auth...
     elseif s === :time_iso8601

test/runtests.jl

@@ -4,7 +4,8 @@ const dir = joinpath(dirname(pathof(HTTP)), "..", "test")
 include("resources/TestRequest.jl")
 
 @testset "HTTP" begin
-    for f in ["ascii.jl",
+    for f in [
+              "ascii.jl",
               "chunking.jl",
               "utils.jl",
               "client.jl",
@@ -21,7 +22,8 @@ include("resources/TestRequest.jl")
               "async.jl",
               "aws4.jl",
               "insert_layers.jl",
-              "mwe.jl"]
+              "mwe.jl",
+             ]
         file = joinpath(dir, f)
         println("Running $file tests...")
         if isfile(file)

test/server.jl

@@ -276,6 +276,11 @@ end # @testset
         if http.message.target == "/internal-error"
             error("internal error")
         end
+        if http.message.target == "/close"
+            HTTP.setstatus(http, 444)
+            close(http.stream)
+            return
+        end
         HTTP.setstatus(http, 200)
         HTTP.setheader(http, "Content-Type" => "text/plain")
         msg = "hello, world"
@@ -308,14 +313,19 @@ end # @testset
         HTTP.get("http://localhost:1234/index.html?a=b")
         HTTP.head("http://localhost:1234")
         HTTP.get("http://localhost:1234/internal-error"; status_exception=false)
+        sleep(1) # necessary to properly forget the closed connection from the previous call
+        try HTTP.get("http://localhost:1234/close"; retry=false) catch end
+        HTTP.get("http://localhost:1234", ["Connection" => "close"])
     end
-    @test length(logs) == 5
+    @test length(logs) == 7
     @test all(x -> x.group === :access, logs)
     @test occursin(r"^127.0.0.1 - - \[(\d{2})/.*/(\d{4}):\d{2}:\d{2}:\d{2}.*\] \"GET / HTTP/1.1\" 200 12$", logs[1].message)
     @test occursin(r"^127.0.0.1 - - \[(\d{2})/.*/(\d{4}):\d{2}:\d{2}:\d{2}.*\] \"GET /index.html HTTP/1.1\" 200 12$", logs[2].message)
     @test occursin(r"^127.0.0.1 - - \[(\d{2})/.*/(\d{4}):\d{2}:\d{2}:\d{2}.*\] \"GET /index.html\?a=b HTTP/1.1\" 200 12$", logs[3].message)
     @test occursin(r"^127.0.0.1 - - \[(\d{2})/.*/(\d{4}):\d{2}:\d{2}:\d{2}.*\] \"HEAD / HTTP/1.1\" 200 0$", logs[4].message)
     @test occursin(r"^127.0.0.1 - - \[(\d{2})/.*/(\d{4}):\d{2}:\d{2}:\d{2}.*\] \"GET /internal-error HTTP/1.1\" 500 \d+$", logs[5].message)
+    @test occursin(r"^127.0.0.1 - - \[(\d{2})/.*/(\d{4}):\d{2}:\d{2}:\d{2}.*\] \"GET /close HTTP/1.1\" 444 0$", logs[6].message)
+    @test occursin(r"^127.0.0.1 - - \[(\d{2})/.*/(\d{4}):\d{2}:\d{2}:\d{2}.*\] \"GET / HTTP/1.1\" 200 12$", logs[7].message)
 
     # Combined Log Format
     logs = with_testserver(combined_logfmt) do
@@ -342,10 +352,6 @@ end # @testset
         HTTP.get("http://localhost:1234/index.html?a=b")
         HTTP.head("http://localhost:1234")
     end
-    @show logs[1].message
-    @show logs[2].message
-    @show logs[3].message
-    @show logs[4].message
     @test length(logs) == 4
     @test all(x -> x.group === :access, logs)
     @test occursin(r"^application/json text/plain GET / HTTP/1\.1 GET / 127\.0\.0\.1 \d+ - HTTP/1\.1 \d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}.* \d+/.*/\d{4}:\d{2}:\d{2}:\d{2}.* 200 12$", logs[1].message)