Further cleanup in logging

6 files changed, 40 insertions, 56 deletions

diff --git a/components/authorize/src/authorize_rpc.erl b/components/authorize/src/authorize_rpc.erl
index 50cd473..287c519 100644
--- a/components/authorize/src/authorize_rpc.erl
+++ b/components/authorize/src/authorize_rpc.erl
@@ -148,8 +148,8 @@ handle_rpc(Other, _Args) ->
 %%
 handle_call({rvi_call, authorize_local_message, Args}, _From, State) ->
     {_, ServiceName} = lists:keyfind(service_name, 1, Args),
-    ?info("authorize_rpc:authorize_local_message(gen_server):  args:            ~p", [ Args]),
-    ?info("authorize_rpc:authorize_local_message(gen_server):  service name:    ~p", [ ServiceName]),
+    ?debug("authorize_rpc:authorize_local_message(gen_server):  args:            ~p", [ Args]),
+    ?debug("authorize_rpc:authorize_local_message(gen_server):  service name:    ~p", [ ServiceName]),
     {reply, authorize_local_message(ServiceName), State};
 
 handle_call({rvi_call, authorize_remote_message, Args}, _From, State) ->
diff --git a/components/data_link_bert_rpc/src/data_link_bert_rpc_rpc.erl b/components/data_link_bert_rpc/src/data_link_bert_rpc_rpc.erl
index 48b9a0b..dd3f7bf 100644
--- a/components/data_link_bert_rpc/src/data_link_bert_rpc_rpc.erl
+++ b/components/data_link_bert_rpc/src/data_link_bert_rpc_rpc.erl
@@ -135,11 +135,9 @@ connect_remote(IP, Port) ->
 
 setup_data_link(RemoteAddress, RemotePort, Service) ->
     { LocalAddress, LocalPort} = rvi_common:node_address_tuple(),
-    ?info("data_link_bert:setup_data_link(): Remote Address:   ~p", [ RemoteAddress]),
-    ?info("data_link_bert:setup_data_link(): Remote Port:      ~p", [ RemotePort]),
-    ?info("data_link_bert:setup_data_link(): Local Address:    ~p", [ LocalAddress]),
-    ?info("data_link_bert:setup_data_link(): Local Port:       ~p", [ LocalPort]),
-    ?info("data_link_bert:setup_data_link(): service:          ~p", [ Service]),
+    ?info("data_link_bert:setup_data_link(): Link:    ~p:~p -> ~p:~p", 
+	  [ LocalAddress, LocalPort, RemoteAddress, RemotePort]),
+    ?info("data_link_bert:setup_data_link(): Service: ~p", [ Service]),
 
     
     case connect_remote(RemoteAddress, RemotePort) of
@@ -150,9 +148,7 @@ setup_data_link(RemoteAddress, RemotePort, Service) ->
 	    ?info("data_link_bert:setup_data_link(): New connection!"),
 
 	    %% Follow up with an authorize.
-	    ?info("data_link_bert:setup_data_link(): ---------------"),
-	    ?info("data_link_bert:setup_data_link(): Sending authorize()"),
-	    ?info("data_link_bert:setup_data_link(): ---------------"),
+	    ?debug("data_link_bert:setup_data_link(): Sending authorize()"),
 	    connection:send(Pid, { authorize, 
 				   1, LocalAddress, LocalPort, rvi_binary, 
 				   {certificate, {}}, { signature, {}} }),
@@ -167,13 +163,13 @@ setup_data_link(RemoteAddress, RemotePort, Service) ->
 
 
 disconnect_data_link(RemoteAddress, RemotePort) ->
-    ?info("data_link_bert:disconnect_data_link(): Remote Address: ~p:~p", [ RemoteAddress, RemotePort]),
+    ?info("data_link_bert:disconnect_data_link(): Remote: ~p:~p", [ RemoteAddress, RemotePort]),
     {ok, [ { status, rvi_common:json_rpc_status(ok)}]}.
 
 
 
 send_data(RemoteAddress, RemotePort, Data) ->
-    ?info("data_link_bert:send_data(): Remote Address: ~p:~p", [ RemoteAddress, RemotePort]),
+    ?info("data_link_bert:send_data(): Remote: ~p:~p", [ RemoteAddress, RemotePort]),
     %% ?info("data_link_bert:send_data(): Data:           ~p", [ Data]),
 
     Res = connection:send(RemoteAddress, RemotePort, {receive_data, Data}),
@@ -189,7 +185,7 @@ send_data(RemoteAddress, RemotePort, Data) ->
 
 
 announce_local_service(Service, Availability) ->
-    ?info("data_link_bert:announce_local_service(~p): Service      ~p",  [Availability, Service]),
+    ?debug("data_link_bert:announce_local_service(~p): Service: ~p",  [Availability, Service]),
     %% Grab our local address.
     { LocalAddress, LocalPort } = rvi_common:node_address_tuple(),
 
@@ -199,8 +195,6 @@ announce_local_service(Service, Availability) ->
     case rvi_common:send_component_request(service_discovery, get_remote_network_addresses, [], 
 					   [ addresses ]) of
 	{ ok, _, [ Addresses ] } -> 
-	    ?info("data_link_bert:announce_local_service(~p): Addresses      ~p", 
-		   [ Availability, Addresses]),
 
 	    %% Grab our local address.
 	    { LocalAddress, LocalPort } = rvi_common:node_address_tuple(),
@@ -208,8 +202,8 @@ announce_local_service(Service, Availability) ->
 	    %% Loop over all returned addresses
 	    lists:map(
 	      fun(Address) ->
-		      ?debug("data_link_bert:announce_local_service(~p): Sending to      ~p", 
-			    [ Availability, Address]),
+		      ?info("data_link_bert:announce_local_service(~p): Announcing ~p to ~p", 
+			    [ Availability, Service, Address]),
 		      
 		      %% Split the address into host and port
 		      [ RemoteAddress, RemotePort] =  string:tokens(Address, ":"),
@@ -247,13 +241,13 @@ handle_socket(FromPid, PeerIP, PeerPort, data,
 		Certificate,
 		Signature}, _ExtraArgs) ->
 
-    ?info("data_link_bert:authorize(): TransactionID:  ~p", [ TransactionID ]),
-    ?info("data_link_bert:authorize(): Peer Address:   {~p, ~p}", [PeerIP, PeerPort ]),
-    ?info("data_link_bert:authorize(): Remote Address: ~p", [ RemoteAddress ]),
-    ?info("data_link_bert:authorize(): Remote Port:    ~p", [ RemotePort ]),
+    ?info("data_link_bert:authorize(): Peer Address:   ~p:~p", [PeerIP, PeerPort ]),
+    ?info("data_link_bert:authorize(): Remote Address: ~p~p", [ RemoteAddress, RemotePort ]),
     ?info("data_link_bert:authorize(): Protocol:       ~p", [ Protocol ]),
-    ?info("data_link_bert:authorize(): Certificate:    ~p", [ Certificate ]),
-    ?info("data_link_bert:authorize(): Signature:      ~p", [ Signature ]),
+    ?debug("data_link_bert:authorize(): TransactionID:  ~p", [ TransactionID ]),
+    ?debug("data_link_bert:authorize(): Certificate:    ~p", [ Certificate ]),
+    ?debug("data_link_bert:authorize(): Signature:      ~p", [ Signature ]),
+
 
     { LocalAddress, LocalPort } = rvi_common:node_address_tuple(),
 
@@ -265,9 +259,8 @@ handle_socket(FromPid, PeerIP, PeerPort, data,
 	case { RemoteAddress, RemotePort } of
 	    { "0.0.0.0", 0 } ->
 		
-		?info("data_link_bert:authorize(): Remote Address is nil."),
-		?info("data_link_bert:authorize(): Will use ~p:~p",  
-		      [PeerIP, PeerPort]),
+		?info("data_link_sms:authorize(): Remote is behind firewall. Will use ~p:~p", 
+		      [ PeerIP, PeerPort]),
 		{ PeerIP, PeerPort };
 
 	    _ -> { RemoteAddress, RemotePort}
@@ -283,12 +276,12 @@ handle_socket(FromPid, PeerIP, PeerPort, data,
 	not_found ->
 	    ?info("data_link_bert:authorize(): New connection!"),
 	    connection_manager:add_connection(NRemoteAddress, NRemotePort, FromPid),
-	    ?info("data_link_bert:authorize(): Sending authorize."),
+	    ?debug("data_link_bert:authorize(): Sending authorize."),
 	    Res = connection:send(FromPid, 
 			    { authorize, 
 			      1, LocalAddress, LocalPort, rvi_binary, 
 			      {certificate, {}}, { signature, {}}}),
-	    ?info("data_link_bert:authorize(): Sending authorize: ~p", [ Res]),
+	    ?debug("data_link_bert:authorize(): Sending authorize: ~p", [ Res]),
 	    ok;
 	_ -> ok
     end,
@@ -311,16 +304,13 @@ handle_socket(FromPid, PeerIP, PeerPort, data,
 			    end,
 			    [], JSONSvc),
 
-	    ?info("data_link_bert:authorize(): Local Services:       ~p", 
-		   [ LocalServices ]),
-
 	    %% Grab our local address.
 	    { LocalAddress, LocalPort } = rvi_common:node_address_tuple(),
 
 	    %% Send an authorize back to the remote node
-	    ?info("data_link_bert:authorize(): -------------------"),
-	    ?info("data_link_bert:authorize(): Sending announce()"),
-	    ?info("data_link_bert:authorize(): -------------------"),
+	    ?info("data_link_sms:authorize(): Announcing local services: ~p to remote ~p:~p",
+		  [LocalServices, NRemoteAddress, NRemotePort]),
+
 	    connection:send(FromPid, 
 			    { service_announce, 2, available,
 			      LocalServices, { signature, {}}});
@@ -466,7 +456,7 @@ handle_rpc("send_data", Args) ->
     send_data(RemoteAddress, list_to_integer(RemotePort), Data);
     
 handle_rpc(Other, _Args) ->
-    ?info("data_link_bert:handle_rpc(~p)", [ Other ]),
+    ?info("data_link_bert:handle_rpc(~p): unknown", [ Other ]),
     { ok, [ { status, rvi_common:json_rpc_status(invalid_command)} ] }.
 
 
@@ -506,10 +496,6 @@ handle_call({rvi_call, send_data, Args}, _From, State) ->
 handle_call({setup_initial_ping, Address, Port, Pid}, _From, St) ->
     %% Create a timer to handle periodic pings.
     {ok, ServerOpts } = rvi_common:get_component_config(data_link, bert_rpc_server, []),
-    ?info("data_link_bert_rpc_rpc:setup_ping(): ~p", 
-	  [ ServerOpts] ),
-										      
-
     Timeout = proplists:get_value(ping_interval, ServerOpts, ?DEFAULT_PING_INTERVAL),
 
     ?info("data_link_bert_rpc_rpc:setup_ping(): ~p:~p will be pinged every ~p msec", 
diff --git a/components/rvi_common/src/rvi_common.erl b/components/rvi_common/src/rvi_common.erl
index 8c772ef..c8525c8 100644
--- a/components/rvi_common/src/rvi_common.erl
+++ b/components/rvi_common/src/rvi_common.erl
@@ -174,7 +174,7 @@ send_component_request(Component, Service, ArgList, ReturnParams) ->
 	    end;
 
 	{ Proc, _ } ->
-	    ?info("Sending ~p:~p to ~p", [Component, Service, Proc]),
+	    ?debug("Sending ~p:~p to ~p", [Component, Service, Proc]),
 	    { Reply, ReplyArg} = gen_server:call(Proc, { rvi_call, Service, ArgList }),
 	    %% Retrieve the status from the reply
 	    [ Status | ReturnValues ] = retrieve_reply_elements([ status | ReturnParams], ReplyArg),
diff --git a/components/schedule/src/schedule.erl b/components/schedule/src/schedule.erl
index 421527f..9624477 100644
--- a/components/schedule/src/schedule.erl
+++ b/components/schedule/src/schedule.erl
@@ -456,13 +456,13 @@ bring_up_data_link(SvcName) ->
 		{ok, already_connected } ->
 		    already_connected;
 		Que -> 
-		    ?info("schedule:bring_up_data_link() Que:~p.", [Que]),
+		    ?info("schedule:bring_up_data_link() Failed:~p.", [Que]),
 		    ok
 	    end;
 
 	{ok, not_found, _ } ->
 	    ?info("schedule:bring_up_data_link() Failed to resolve remote Service: ~p."
-		  "Service not found.", 
+		  " Service not found.", 
 		  [ SvcName ]),
 	    not_found;
 
diff --git a/components/service_discovery/src/service_discovery_rpc.erl b/components/service_discovery/src/service_discovery_rpc.erl
index cce7898..10aaf79 100644
--- a/components/service_discovery/src/service_discovery_rpc.erl
+++ b/components/service_discovery/src/service_discovery_rpc.erl
@@ -115,8 +115,6 @@ register_remote_service(Service, NetworkAddress) ->
 
 
 unregister_remote_services_by_address(NetworkAddress) ->
-    ?info("service_discovery_rpc:unregister_remote_services_by_address(): network_address: ~p", 
-	  [NetworkAddress]),
 
     %% Delete all services registered under the given address.
     Svcs = ets:lookup(?REMOTE_ADDRESS_TABLE, NetworkAddress),
@@ -262,7 +260,7 @@ unregister_remote_services_by_name(Services) ->
     {ok, [ { status, rvi_common:json_rpc_status(ok)}]}.
 
 unregister_local_service(Service) ->
-    ?info("service_discovery_rpc:unregister_local_service(): Service~p", 
+    ?info("service_discovery_rpc:unregister_local_service(): ~p", 
 	  [Service]),
 
     ets:delete(?LOCAL_SERVICE_TABLE, Service),
@@ -306,7 +304,7 @@ resolve_remote_service(RawService) ->
 		   { network_address, NetworkAddress }]};
 
 	not_found ->
-	    ?info("service_discovery_rpc:resolve_remote_service(~p): Service not found in ets. "
+	    ?debug("service_discovery_rpc:resolve_remote_service(~p): Service not found in ets. "
 		  "Trying static nodes",
 		  [Service]),
 
@@ -314,13 +312,13 @@ resolve_remote_service(RawService) ->
 	    %% Check if this is a service residing on the backend server
 	    case rvi_common:get_static_node(Service) of
 		not_found -> %% Not found
-		    ?info("service_discovery_rpc:resolve_remote_service(~p): Service not found in static nodes.", 
+		    ?info("service_discovery_rpc:resolve_remote_service(~p): Service not found.", 
 			   [Service]),
 		    
 		    { ok, [ { status, rvi_common:json_rpc_status(not_found) }]};
 
 		NetworkAddress -> %% Found
-			    ?info("service_discovery_rpc:resolve_service(~p): Service is on static node ~p", 
+			    ?debug("service_discovery_rpc:resolve_service(~p): Service is on static node ~p", 
 				   [Service, NetworkAddress]),
 
 		    {ok, [ { status, rvi_common:json_rpc_status(ok) },
@@ -389,7 +387,7 @@ get_services(Table) ->
 				 [ {ServiceName, ServiceAddr } | Acc ] end, 
 			 [], Table),
 
-    ?info("service_discovery_rpc:get_services(): ~p", [ Services]),
+    ?debug("service_discovery_rpc:get_services(): ~p", [ Services ]),
     Services.
 
 get_all_services() ->
@@ -402,7 +400,7 @@ get_all_services() ->
 			  [], ?LOCAL_SERVICE_TABLE),
 
     Services = RemoteSvc++LocalSvc,
-    ?info("service_discovery_rpc:get_all_services(): ~p", [ Services]),
+    ?debug("service_discovery_rpc:get_all_services(): ~p", [ Services]),
     Services.
 
 
@@ -416,7 +414,7 @@ get_json_services(Table) ->
 				    ]
 				   } | Acc ] end, 
 			 [], Table),
-    ?info("service_discovery_rpc:get_services(): ~p", [ Services]),
+    ?debug("service_discovery_rpc:get_services(): ~p", [ Services]),
     {ok, [ { status, rvi_common:json_rpc_status(ok) },
 	   { services, {array, Services }}]}.
 
@@ -438,7 +436,7 @@ get_network_addresses_(Table) ->
 
     %% Return a dup-scrubbed list.
     Addresses = sets:to_list(sets:from_list(AddrList)),
-    ?info("service_discovery_rpc:get_network_addresses(~p): ~p", [ Table, Addresses ]),
+    ?debug("service_discovery_rpc:get_network_addresses(~p): ~p", [ Table, Addresses ]),
     Addresses.
 
 
@@ -551,7 +549,7 @@ handle_rpc("get_local_network_addresses", _Args) ->
 %% Handle the rest.
 %%
 handle_rpc( Other, _Args) ->
-    ?info("service_discovery_rpc:handle_rpc(~p)", [ Other ]),
+    ?info("service_discovery_rpc:handle_rpc(~p): unknown", [ Other ]),
     { ok, [ { status, rvi_common:json_rpc_status(invalid_command)} ] }.
 
 
diff --git a/components/service_edge/src/service_edge_rpc.erl b/components/service_edge/src/service_edge_rpc.erl
index 596f9de..e8d98b5 100644
--- a/components/service_edge/src/service_edge_rpc.erl
+++ b/components/service_edge/src/service_edge_rpc.erl
@@ -309,7 +309,7 @@ flatten_ws_args(Args) ->
 
 dispatch_to_local_service([ $w, $s, $: | WSPidStr], services_available, 
 			  [{ services, Services}] ) ->
-    ?info("service_edge:dispatch_to_local_service(service_available): Websocket!: ~p", [ Services]),
+    ?info("service_edge:dispatch_to_local_service(service_available, websock): ~p", [ Services]),
     wse:call(list_to_pid(WSPidStr), wse:window(),
 	     "services_available", 
 	     [ "services", Services ]),
@@ -317,7 +317,7 @@ dispatch_to_local_service([ $w, $s, $: | WSPidStr], services_available,
 
 dispatch_to_local_service([ $w, $s, $: | WSPidStr], services_unavailable, 
 			  [{ services, Services}] ) ->
-    ?info("service_edge:dispatch_to_local_service(service_unavailable): Websocket!: ~p", [ Services]),
+    ?info("service_edge:dispatch_to_local_service(service_unavailable, websock): ~p", [ Services]),
     wse:call(list_to_pid(WSPidStr), wse:window(),
 	     "services_unavailable", 
 	     [ "services", Services ]),
@@ -325,7 +325,7 @@ dispatch_to_local_service([ $w, $s, $: | WSPidStr], services_unavailable,
 
 dispatch_to_local_service([ $w, $s, $: | WSPidStr], message, 
 			 [{ service_name, SvcName}, { parameters, Args}] ) ->
-    ?info("service_edge:dispatch_to_local_service(message): Websocket!:~p", [Args]),
+    ?info("service_edge:dispatch_to_local_service(message, websock): ~p", [Args]),
     wse:call(list_to_pid(WSPidStr), wse:window(),
 	     "message", 
 	     [ "service_name", SvcName ] ++ flatten_ws_args(Args)),