From 8b85c86ebe1ea0299bf0f046c18f6d7666f5b80e Mon Sep 17 00:00:00 2001
From: Brandon Simmons <brandon.m.simmons@gmail.com>
Date: Wed, 8 Apr 2020 11:59:46 -0400
Subject: [PATCH] Fix erroneous error logging in WebSocket.onStop

---
 CHANGELOG.md                                        |  1 +
 .../src-lib/Hasura/GraphQL/Transport/WebSocket.hs   | 13 ++++++++++---
 2 files changed, 11 insertions(+), 3 deletions(-)

diff --git a/CHANGELOG.md b/CHANGELOG.md
index 939a0311b77..df45873fbc4 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -64,6 +64,7 @@ Read more about check constraints on [Postgres Docs](https://www.postgresql.org/
 - server: preserve cookie headers from sync action webhook (close #4021)
 - server: validate action webhook response to conform to action output type (fix #3977)
 - server: add 'ID' to default scalars in custom types (fix #4061)
+- server: fix erroneous error log "Received STOP for an operation ..."
 - console: enum field values can be selected through a dropdown in insert/edit rows page (close #3748) (#3810)
 - console: exported metadata filenames are now unique(`hasura_metadata_<timestamp>.json`) (close #1772) (#4106)
 - console: allow bulk deleting rows in 'Browse Rows' section (close #1739) (#3735)
diff --git a/server/src-lib/Hasura/GraphQL/Transport/WebSocket.hs b/server/src-lib/Hasura/GraphQL/Transport/WebSocket.hs
index 2e8f2c6acc3..3102cd6cc8e 100644
--- a/server/src-lib/Hasura/GraphQL/Transport/WebSocket.hs
+++ b/server/src-lib/Hasura/GraphQL/Transport/WebSocket.hs
@@ -487,15 +487,22 @@ onMessage authMode serverEnv wsConn msgRaw =
 
 onStop :: WSServerEnv -> WSConn -> StopMsg -> IO ()
 onStop serverEnv wsConn (StopMsg opId) = do
+  -- When a stop message is received for an operation, it may not be present in OpMap
+  -- in these cases:
+  -- 1. If the operation is a query/mutation - as we remove the operation from the
+  -- OpMap as soon as it is executed
+  -- 2. A misbehaving client
+  -- 3. A bug on our end
   opM <- liftIO $ STM.atomically $ STMMap.lookup opId opMap
   case opM of
     Just (lqId, opNameM) -> do
       logWSEvent logger wsConn $ EOperation $ opDet opNameM
       LQ.removeLiveQuery logger lqMap lqId
     Nothing    ->
-      L.unLogger logger $ L.UnstructuredLog L.LevelError $ fromString $
-        "Received STOP for an operation "<>(show opId)<>" we have no record for. "<>
-        "this could be a misbehaving client or a bug"
+      L.unLogger logger $ L.UnstructuredLog L.LevelDebug $ fromString $
+        "Received STOP for an operation that we have no record for: "
+        <> show (unOperationId opId)
+        <> " (could be a query/mutation operation or a misbehaving client or a bug)"
   STM.atomically $ STMMap.delete opId opMap
   where
     logger = _wseLogger serverEnv