From ec2accd9d746609b2b52ffcec4a19c71ff9b2b2c Mon Sep 17 00:00:00 2001 From: rusefi Date: Sat, 25 Jul 2020 19:52:53 -0400 Subject: [PATCH] more, more logs! --- .../src/main/java/com/rusefi/server/Backend.java | 11 +++++++---- .../com/rusefi/server/ControllerConnectionState.java | 1 + .../com/rusefi/server/JsonUserDetailsResolver.java | 11 +++++++---- .../main/java/com/rusefi/server/TwoKindSemaphore.java | 5 +++++ 4 files changed, 20 insertions(+), 8 deletions(-) diff --git a/java_tools/proxy_server/src/main/java/com/rusefi/server/Backend.java b/java_tools/proxy_server/src/main/java/com/rusefi/server/Backend.java index 9a414e8ab7..b6df0649ef 100644 --- a/java_tools/proxy_server/src/main/java/com/rusefi/server/Backend.java +++ b/java_tools/proxy_server/src/main/java/com/rusefi/server/Backend.java @@ -34,6 +34,7 @@ import java.util.concurrent.atomic.AtomicLong; import static com.devexperts.logging.Logging.getLogging; import static com.rusefi.Timeouts.SECOND; +import static com.rusefi.server.Birthday.humanReadableFormat; /** * See NetworkConnectorStartup - NetworkConnector connects an ECU to this backend @@ -254,6 +255,7 @@ public class Backend implements Closeable { register(controllerConnectionState); } catch (Throwable e) { + log.error("runControllerConnector close " + controllerConnectionState, e); close(controllerConnectionState); } }, serverPortForControllers, "ControllerServer", serverSocketCreationCallback, BinaryProtocolServer.SECURE_SOCKET_FACTORY); @@ -323,13 +325,13 @@ public class Backend implements Closeable { applications = new ArrayList<>(this.applications); } - long now = System.currentTimeMillis(); for (ApplicationConnectionState client : applications) { - if (now - client.getClientStream().getStreamStats().getPreviousPacketArrivalTime() > applicationTimeout) { + long timeSinceLastActivity = System.currentTimeMillis() - client.getClientStream().getStreamStats().getPreviousPacketArrivalTime(); + if (timeSinceLastActivity > applicationTimeout) { log.error("Kicking out application " + client); close(client); } else { - log.info("Looks alive " + client); + log.info("Looks alive " + client + " time since last activity: " + humanReadableFormat(timeSinceLastActivity)); } } @@ -339,7 +341,8 @@ public class Backend implements Closeable { } for (ControllerConnectionState controllerConnectionState : controllers) { - log.info("State: " + controllerConnectionState); + long timeSinceLastActivity = System.currentTimeMillis() - controllerConnectionState.getStream().getStreamStats().getPreviousPacketArrivalTime(); + log.info("State: " + controllerConnectionState + " time since last activity: " + humanReadableFormat(timeSinceLastActivity)); } } diff --git a/java_tools/proxy_server/src/main/java/com/rusefi/server/ControllerConnectionState.java b/java_tools/proxy_server/src/main/java/com/rusefi/server/ControllerConnectionState.java index 9d9dfbfa79..93e2ee4536 100644 --- a/java_tools/proxy_server/src/main/java/com/rusefi/server/ControllerConnectionState.java +++ b/java_tools/proxy_server/src/main/java/com/rusefi/server/ControllerConnectionState.java @@ -137,6 +137,7 @@ public class ControllerConnectionState { getOutputs(); } catch (IOException e) { // todo: this is currently not covered by a unit test + log.error("grabOutputs " + this, e); backend.close(this); } } diff --git a/java_tools/proxy_server/src/main/java/com/rusefi/server/JsonUserDetailsResolver.java b/java_tools/proxy_server/src/main/java/com/rusefi/server/JsonUserDetailsResolver.java index 05cd23bd89..479f453cdb 100644 --- a/java_tools/proxy_server/src/main/java/com/rusefi/server/JsonUserDetailsResolver.java +++ b/java_tools/proxy_server/src/main/java/com/rusefi/server/JsonUserDetailsResolver.java @@ -1,5 +1,6 @@ package com.rusefi.server; +import com.devexperts.logging.Logging; import com.rusefi.tools.online.HttpUtil; import org.jetbrains.annotations.Nullable; import org.json.simple.JSONObject; @@ -8,6 +9,8 @@ import org.json.simple.parser.ParseException; import java.io.IOException; public class JsonUserDetailsResolver implements UserDetailsResolver { + private final static Logging log = Logging.getLogging(JsonUserDetailsResolver.class); + @Override @Nullable public UserDetails apply(String authToken) { @@ -15,10 +18,10 @@ public class JsonUserDetailsResolver implements UserDetailsResolver { try { String responseString = HttpUtil.executeGet(HttpUtil.RUSEFI_ONLINE_JSON_API_PREFIX + "getUserByToken&rusefi_token=" + authToken); JSONObject json = HttpUtil.getJsonResponse(responseString); - System.out.println("String " + json); + log.info("String " + json); Object getUserByToken = json.get("getUserByToken"); if (getUserByToken instanceof String) { - System.out.println("AUTH FAILED: Result " + getUserByToken); + log.info("AUTH FAILED: Result " + getUserByToken); return null; } JSONObject details = (JSONObject) getUserByToken; @@ -26,10 +29,10 @@ public class JsonUserDetailsResolver implements UserDetailsResolver { String name = (String) details.get("NAME"); UserDetails result = new UserDetails(name, Integer.parseInt(id)); - System.out.println("AUTH SUCCESS " + result); + log.info("AUTH SUCCESS " + result); return result; } catch (IOException | ParseException e) { - System.out.println("JsonUserDetailsResolver error" + e); + log.error("JsonUserDetailsResolver error" + e); e.printStackTrace(); return null; } diff --git a/java_tools/proxy_server/src/main/java/com/rusefi/server/TwoKindSemaphore.java b/java_tools/proxy_server/src/main/java/com/rusefi/server/TwoKindSemaphore.java index 5cc695786b..38729ffc5e 100644 --- a/java_tools/proxy_server/src/main/java/com/rusefi/server/TwoKindSemaphore.java +++ b/java_tools/proxy_server/src/main/java/com/rusefi/server/TwoKindSemaphore.java @@ -1,9 +1,13 @@ package com.rusefi.server; +import com.devexperts.logging.Logging; + import java.util.concurrent.Semaphore; import java.util.concurrent.TimeUnit; public class TwoKindSemaphore { + private final static Logging log = Logging.getLogging(TwoKindSemaphore.class); + // we have to distinguish between long-term usage by application and short-term usage just to refresh gauges private final static int LONG_TERM = 2; private final static int SHORT_TERM = 1; @@ -11,6 +15,7 @@ public class TwoKindSemaphore { private UserDetails owner; public void releaseFromLongTermUsage() { + log.info("release " + owner); semaphore.release(LONG_TERM); // not atomic but that's fine, isUsed is the source of truth owner = null;