Split up http request and debug log each step

2 files changed, 15 insertions, 4 deletions

diff --git a/Emakefile b/Emakefile
index fe4b31d..dc13e9c 100644
--- a/Emakefile
+++ b/Emakefile
@@ -2,6 +2,7 @@
 {["src/*", "test/*"],
  [debug_info,
   {i, "include/"},
+  {i, "../"},
   {outdir, "ebin/"},
   {parse_transform, lager_transform}]}.
 {["test/src/*"],
diff --git a/src/plop.erl b/src/plop.erl
index d2a8fc3..780dcbe 100644
--- a/src/plop.erl
+++ b/src/plop.erl
@@ -39,6 +39,7 @@
 %%-include("db.hrl").
 -include_lib("public_key/include/public_key.hrl").
 -include_lib("eunit/include/eunit.hrl").
+-include_lib("hackney/include/hackney_lib.hrl").
 
 %%%%% moved from plop.hrl, maybe remove
 -define(PLOPVERSION, 0).
@@ -193,13 +194,22 @@ storage_nodes_quorum() ->
     {ok, Value} = application:get_env(plop, storage_nodes_quorum),
     Value.
 
-send_http_request(URL, Headers, RequestBody) ->
+send_http_request(TreeLeafHash, URL, Headers, RequestBody) ->
     ParentPid = self(),
     RequestId = make_ref(),
     CACertFile = application:get_env(catlfish, https_cacertfile, none),
     spawn(fun () ->
-                  {ok, StatusCode, RespHeaders, ClientRef} = hackney:post(URL, Headers, RequestBody, [{ssl_options, [{cacertfile, CACertFile}]}]),
+                  Starttime = os:timestamp(),
+                  ParsedURL = hackney_url:parse_url(URL),
+                  #hackney_url{path = Path} = ParsedURL,
+                  lager:debug("leafhash ~s: sending http request to ~p", [mochihex:to_hex(TreeLeafHash), URL]),
+                  {ok, ConnRef} = hackney:connect(ParsedURL, [{ssl_options, [{cacertfile, CACertFile}]}]),
+                  lager:debug("leafhash ~s: connected to ~p", [mochihex:to_hex(TreeLeafHash), URL]),
+                  {ok, StatusCode, RespHeaders, ClientRef} = hackney:send_request(ConnRef, {post, Path, Headers, RequestBody}),
+                  lager:debug("leafhash ~s: received headers for ~p", [mochihex:to_hex(TreeLeafHash), URL]),
                   {ok, Body} = hackney:body(ClientRef),
+                  Stoptime = os:timestamp(),
+                  lager:debug("leafhash ~s: received body for ~p: time ~p", [mochihex:to_hex(TreeLeafHash), URL, timer:now_diff(Stoptime, Starttime)]),
                   StatusLine = {none, StatusCode, none},
                   ParentPid ! {http, {RequestId, {StatusLine, RespHeaders, Body}}}
           end),
@@ -213,7 +223,7 @@ send_storage_sendentry(URLBase, LogEntry, TreeLeafHash) ->
                  ]}),
     lager:debug("leafhash ~s: send sendentry to storage node ~p",
                 [mochihex:to_hex(TreeLeafHash), URLBase]),
-    RequestId = send_http_request(URLBase ++ "sendentry", [{"Content-Type", "text/json"}], list_to_binary(Request)),
+    RequestId = send_http_request(TreeLeafHash, URLBase ++ "sendentry", [{"Content-Type", "text/json"}], list_to_binary(Request)),
     {RequestId, URLBase}.
 
 send_storage_entrycommitted(URLBase, EntryHash, TreeLeafHash) ->
@@ -222,7 +232,7 @@ send_storage_entrycommitted(URLBase, EntryHash, TreeLeafHash) ->
                   {entryhash, base64:encode(EntryHash)},
                   {treeleafhash, base64:encode(TreeLeafHash)}
                  ]}),
-    send_http_request(URLBase ++ "entrycommitted", [{"Content-Type", "text/json"}], list_to_binary(Request)).
+    send_http_request(TreeLeafHash, URLBase ++ "entrycommitted", [{"Content-Type", "text/json"}], list_to_binary(Request)).
 
 store_loop(TreeLeafHash, Requests, RepliesUntilQuorum) ->
     receive