Add a basic log page; tweaks.

This tweaks @mrmr1993's logging ideas discussed in #1629:

- Do not generate log entries from the logging page itself.
- Use the logger for *all* logging (including from `commands.coffee`, and from `bgLog`).

@mrmr1993's original idea is 91fb337c9d92f6291ef42c55c4d29ca35b710203.

3 files changed, 27 insertions, 17 deletions

diff --git a/background_scripts/commands.coffee b/background_scripts/commands.coffee
index c8121a96..50306c35 100644
--- a/background_scripts/commands.coffee
+++ b/background_scripts/commands.coffee
@@ -13,7 +13,7 @@ Commands =
   #    command passed to it. This is used to implement e.g. "closing of 3 tabs".
   addCommand: (command, description, options) ->
     if command of @availableCommands
-      console.log(command, "is already defined! Check commands.coffee for duplicates.")
+      logMessage? "#{command} is already defined! Check commands.coffee for duplicates."
       return
 
     options ||= {}
@@ -26,7 +26,7 @@ Commands =
 
   mapKeyToCommand: ({ key, command, options }) ->
     unless @availableCommands[command]
-      console.log command, "doesn't exist!"
+      logMessage? "#{command} doesn't exist!"
       return
 
     options ?= []
@@ -55,13 +55,13 @@ Commands =
             [ _, key, command, options... ] = tokens
             if command? and @availableCommands[command]
               key = @normalizeKey key
-              console.log "Mapping", key, "to", command
+              logMessage? "Mapping #{key} to #{command}"
               @mapKeyToCommand { key, command, options }
 
           when "unmap"
             if tokens.length == 2
               key = @normalizeKey tokens[1]
-              console.log "Unmapping", key
+              logMessage? "Unmapping #{key}"
               delete @keyToCommandRegistry[key]
 
           when "unmapAll"
diff --git a/background_scripts/main.coffee b/background_scripts/main.coffee
index 2c93f6fb..63729b8f 100644
--- a/background_scripts/main.coffee
+++ b/background_scripts/main.coffee
@@ -72,11 +72,12 @@ completionHandlers =
   refresh: (completer, _, port) -> completer.refresh port
   cancel: (completer, _, port) -> completer.cancel port
 
-handleCompletions = (request, port) ->
+handleCompletions = (sender) -> (request, port) ->
   completionHandlers[request.handler] completers[request.name], request, port
 
 chrome.runtime.onConnect.addListener (port, name) ->
-  senderTabId = if port.sender.tab then port.sender.tab.id else null
+  sender = port.sender
+  senderTabId = sender.tab?.id
   # If this is a tab we've been waiting to open, execute any "tab loaded" handlers, e.g. to restore
   # the tab's scroll position. Wait until domReady before doing this; otherwise operations like restoring
   # the scroll position will not be possible.
@@ -88,7 +89,7 @@ chrome.runtime.onConnect.addListener (port, name) ->
       toCall.call()
 
   if (portHandlers[port.name])
-    port.onMessage.addListener(portHandlers[port.name])
+    port.onMessage.addListener portHandlers[port.name] sender
 
 chrome.runtime.onMessage.addListener((request, sender, sendResponse) ->
   if (sendRequestHandlers[request.handler])
@@ -96,10 +97,17 @@ chrome.runtime.onMessage.addListener((request, sender, sendResponse) ->
   # Ensure the sendResponse callback is freed.
   return false)
 
-logMessage = (message) ->
-  for viewWindow in chrome.extension.getViews {type: "tab"}
-    if viewWindow.location.pathname == "/pages/logging.html"
-      viewWindow.document.getElementById("log-text").value += "#{(new Date()).toISOString()}: #{message}\n"
+# Log messages to the extension's logging page, but only if that page is open.
+logMessage = do ->
+  loggingPageUrl = chrome.runtime.getURL "pages/logging.html"
+  console.log "Vimium logging URL:\n  #{loggingPageUrl}" if loggingPageUrl? # Do not output URL for tests.
+  (message, sender = null) ->
+    for viewWindow in chrome.extension.getViews {type: "tab"}
+      if viewWindow.location.pathname == "/pages/logging.html"
+        # Don't log messages from the logging page itself.  We do this check late because most of the time
+        # it's not needed.
+        if sender?.url != loggingPageUrl
+          viewWindow.document.getElementById("log-text").value += "#{(new Date()).toISOString()}: #{message}\n"
 
 #
 # Used by the content scripts to get their full URL. This is needed for URLs like "view-source:http:# .."
@@ -515,15 +523,15 @@ splitKeyQueue = (queue) ->
 
   { count: count, command: command }
 
-handleKeyDown = (request, port) ->
+handleKeyDown = (sender) -> (request, port) ->
   key = request.keyChar
   if (key == "<ESC>")
-    logMessage "clearing keyQueue"
+    logMessage "clearing keyQueue", sender
     keyQueue = ""
   else
-    logMessage "checking keyQueue: [#{keyQueue + key}]"
+    logMessage "checking keyQueue: [#{keyQueue + key}]", sender
     keyQueue = checkKeyQueue(keyQueue + key, port.sender.tab.id, request.frameId)
-    logMessage "new KeyQueue: #{keyQueue}"
+    logMessage "new KeyQueue: #{keyQueue}", sender
   # Tell the content script whether there are keys in the queue.
   # FIXME: There is a race condition here.  The behaviour in the content script depends upon whether this message gets
   # back there before or after the next keystroke.
@@ -643,9 +651,9 @@ cycleToFrame = (frames, frameId, count = 0) ->
 sendMessageToFrames = (request, sender) ->
   chrome.tabs.sendMessage sender.tab.id, request.message
 
-# For debugging only. This allows content scripts to log messages to the background page's console.
+# For debugging only. This allows content scripts to log messages to the extension's logging page.
 bgLog = (request, sender) ->
-  console.log "#{sender.tab.id}/#{request.frameId}", request.message
+  logMessage "#{sender.tab.id}/#{request.frameId} #{request.message}", sender
 
 # Port handler mapping
 portHandlers =
@@ -746,3 +754,4 @@ chrome.windows.getAll { populate: true }, (windows) ->
 showUpgradeMessage()
 
 root.TabOperations = TabOperations
+root.logMessage = logMessage
diff --git a/tests/unit_tests/test_chrome_stubs.coffee b/tests/unit_tests/test_chrome_stubs.coffee
index 8814ab23..8b816cd4 100644
--- a/tests/unit_tests/test_chrome_stubs.coffee
+++ b/tests/unit_tests/test_chrome_stubs.coffee
@@ -17,6 +17,7 @@ global.document =
 
 exports.chrome =
   runtime:
+    getURL: ->
     getManifest: () ->
       version: "1.2.3"
     onConnect: