#844 pull request merged and resolved.

Author: grleachman

RetailCoder.VBE/App.cs

@@ -186,7 +186,7 @@ async void sink_ProjectRemoved(object sender, DispatcherEventArgs<VBProject> e)
         {
             if (e.Item.Protection == vbext_ProjectProtection.vbext_pp_locked)
             {
-                Debug.WriteLine(string.Format("Locked project '{0}' was removed.", e.Item.Name));
+                _logger.Debug("Locked project '{0}' was removed.", e.Item.Name);
                 return;
             }
 
@@ -195,7 +195,7 @@ async void sink_ProjectRemoved(object sender, DispatcherEventArgs<VBProject> e)
             _referencesEventsSinks.Remove(projectId);
             _parser.State.RemoveProject(e.Item);
 
-            Debug.WriteLine(string.Format("Project '{0}' was removed.", e.Item.Name));
+            _logger.Debug("Project '{0}' was removed.", e.Item.Name);
             Tuple<IConnectionPoint, int> componentsTuple;
             if (_componentsEventsConnectionPoints.TryGetValue(projectId, out componentsTuple))
             {
@@ -219,10 +219,10 @@ async void sink_ProjectRemoved(object sender, DispatcherEventArgs<VBProject> e)
 
         async void sink_ProjectAdded(object sender, DispatcherEventArgs<VBProject> e)
         {
-            Debug.WriteLine(string.Format("Project '{0}' was added.", e.Item.Name));
+            _logger.Debug("Project '{0}' was added.", e.Item.Name);
             if (e.Item.Protection == vbext_ProjectProtection.vbext_pp_locked)
             {
-                Debug.WriteLine("Project is protected and will not be added to parser state.");
+                _logger.Debug("Project is protected and will not be added to parser state.");
                 return;
             }
 
@@ -246,7 +246,7 @@ private void RegisterComponentsEventSink(VBComponents components, string project
             if (_componentsEventsSinks.ContainsKey(projectId))
             {
                 // already registered - this is caused by the initial load+rename of a project in the VBE
-                Debug.WriteLine("Components sink already registered.");
+                _logger.Debug("Components sink already registered.");
                 return;
             }
 
@@ -269,7 +269,7 @@ private void RegisterComponentsEventSink(VBComponents components, string project
             connectionPoint.Advise(componentsSink, out cookie);
 
             _componentsEventsConnectionPoints.Add(projectId, Tuple.Create(connectionPoint, cookie));
-            Debug.WriteLine("Components sink registered and advising.");
+            _logger.Debug("Components sink registered and advising.");
         }
 
         async void sink_ComponentSelected(object sender, DispatcherEventArgs<VBComponent> e)
@@ -279,7 +279,7 @@ async void sink_ComponentSelected(object sender, DispatcherEventArgs<VBComponent
                 return;
             }
 
-            Debug.WriteLine(string.Format("Component '{0}' was selected.", e.Item.Name));
+            _logger.Debug("Component '{0}' was selected.", e.Item.Name);
             // do something?
         }
 
@@ -290,7 +290,7 @@ async void sink_ComponentRenamed(object sender, DispatcherRenamedEventArgs<VBCom
                 return;
             }
 
-            Debug.WriteLine("Component '{0}' was renamed to '{1}'.", e.OldName, e.Item.Name);
+            _logger.Debug("Component '{0}' was renamed to '{1}'.", e.OldName, e.Item.Name);
 
             _parser.State.RemoveRenamedComponent(e.Item, e.OldName);
         }
@@ -302,7 +302,7 @@ async void sink_ComponentRemoved(object sender, DispatcherEventArgs<VBComponent>
                 return;
             }
 
-            Debug.WriteLine(string.Format("Component '{0}' was removed.", e.Item.Name));
+            _logger.Debug("Component '{0}' was removed.", e.Item.Name);
             _parser.State.ClearStateCache(e.Item, true);
         }
 
@@ -313,7 +313,7 @@ async void sink_ComponentReloaded(object sender, DispatcherEventArgs<VBComponent
                 return;
             }
 
-            Debug.WriteLine(string.Format("Component '{0}' was reloaded.", e.Item.Name));
+            _logger.Debug("Component '{0}' was reloaded.", e.Item.Name);
             _parser.State.OnParseRequested(sender, e.Item);
         }
 
@@ -324,7 +324,7 @@ async void sink_ComponentAdded(object sender, DispatcherEventArgs<VBComponent> e
                 return;
             }
 
-            Debug.WriteLine(string.Format("Component '{0}' was added.", e.Item.Name));
+            _logger.Debug("Component '{0}' was added.", e.Item.Name);
             _parser.State.OnParseRequested(sender, e.Item);
         }
 
@@ -335,7 +335,7 @@ async void sink_ComponentActivated(object sender, DispatcherEventArgs<VBComponen
                 return;
             }
 
-            Debug.WriteLine(string.Format("Component '{0}' was activated.", e.Item.Name));
+            _logger.Debug("Component '{0}' was activated.", e.Item.Name);
             // do something?
         }
 
@@ -346,7 +346,7 @@ async void sink_ProjectRenamed(object sender, DispatcherRenamedEventArgs<VBProje
                 return;
             }
 
-            Debug.WriteLine("Project '{0}' (ID {1}) was renamed to '{2}'.", e.OldName, e.Item.HelpFile, e.Item.Name);
+            _logger.Debug("Project '{0}' (ID {1}) was renamed to '{2}'.", e.OldName, e.Item.HelpFile, e.Item.Name);
             _parser.State.RemoveProject(e.Item.HelpFile);
             _parser.State.OnParseRequested(sender);
         }
@@ -358,7 +358,7 @@ async void sink_ProjectActivated(object sender, DispatcherEventArgs<VBProject> e
                 return;
             }
 
-            Debug.WriteLine(string.Format("Project '{0}' was activated.", e.Item.Name));
+            _logger.Debug("Project '{0}' was activated.", e.Item.Name);
             // do something?
         }
         #endregion
@@ -371,7 +371,7 @@ private void _stateBar_Refresh(object sender, EventArgs e)
 
         private void Parser_StateChanged(object sender, EventArgs e)
         {
-            Debug.WriteLine("App handles StateChanged ({0}), evaluating menu states...", _parser.State.Status);
+            _logger.Debug("App handles StateChanged ({0}), evaluating menu states...", _parser.State.Status);
             _appMenus.EvaluateCanExecute(_parser.State);
         }
 

RetailCoder.VBE/Common/Hotkeys/Hotkey.cs

@@ -4,6 +4,7 @@
 using System.Windows.Forms;
 using System.Windows.Input;
 using Rubberduck.Common.WinAPI;
+using NLog;
 
 namespace Rubberduck.Common.Hotkeys
 {
@@ -12,6 +13,7 @@ public class Hotkey : IHotkey
         private readonly string _key;
         private readonly ICommand _command;
         private readonly IntPtr _hWndVbe;
+        private static readonly Logger _logger = LogManager.GetCurrentClassLogger();
 
         public Hotkey(IntPtr hWndVbe, string key, ICommand command, Keys secondKey = Keys.None)
         {
@@ -82,13 +84,13 @@ private void HookKey(Keys key, uint shift)
             var success = User32.RegisterHotKey(_hWndVbe, hookId, shift, (uint)key);
             if (!success)
             {
-                Debug.WriteLine(Rubberduck.UI.RubberduckUI.CommonHotkey_KeyNotRegistered, key);
+                _logger.Debug(Rubberduck.UI.RubberduckUI.CommonHotkey_KeyNotRegistered, key);
                 //throw new Win32Exception(Rubberduck.UI.RubberduckUI.CommonHotkey_KeyNotRegistered, key);
             }
 
             HotkeyInfo = new HotkeyInfo(hookId, Combo);
             IsAttached = true;
-            Debug.WriteLine("Hotkey '{0}' hooked successfully to command '{1}'", Key, Command.GetType());  //no translation needed for Debug.Writeline
+            _logger.Debug("Hotkey '{0}' hooked successfully to command '{1}'", Key, Command.GetType());  //no translation needed for Debug.Writeline
         }
 
         private static readonly IDictionary<char,uint> Modifiers = new Dictionary<char, uint>

RetailCoder.VBE/Common/RubberduckHooks.cs

@@ -11,6 +11,7 @@
 using Rubberduck.Settings;
 using Rubberduck.UI.Command;
 using Rubberduck.UI.Command.Refactorings;
+using NLog;
 
 namespace Rubberduck.Common
 {
@@ -28,6 +29,7 @@ public class RubberduckHooks : IRubberduckHooks
         private readonly IEnumerable<ICommand> _commands;
         private readonly IList<IAttachable> _hooks = new List<IAttachable>();
         private readonly IDictionary<RubberduckHotkey, ICommand> _mappings;
+        private static readonly Logger _logger = LogManager.GetCurrentClassLogger();
 
         public RubberduckHooks(VBE vbe, IGeneralConfigService config, IEnumerable<ICommand> commands)
         {
@@ -151,7 +153,7 @@ public void Attach()
             }
             catch (Win32Exception exception)
             {
-                Debug.WriteLine(exception);
+                _logger.Error(exception);
             }
         }
 
@@ -172,7 +174,7 @@ public void Detach()
             }
             catch (Win32Exception exception)
             {
-                Debug.WriteLine(exception);
+                _logger.Error(exception);
             }
             IsAttached = false;
         }
@@ -182,12 +184,12 @@ private void hook_MessageReceived(object sender, HookEventArgs e)
             var hotkey = sender as IHotkey;
             if (hotkey != null)
             {
-                Debug.WriteLine("Hotkey message received");
+                _logger.Debug("Hotkey message received");
                 hotkey.Command.Execute(null);
                 return;
             }
 
-            Debug.WriteLine("Unknown message received");
+            _logger.Debug("Unknown message received");
             OnMessageReceived(sender, e);
         }
 
@@ -221,7 +223,7 @@ private IntPtr WindowProc(IntPtr hWnd, uint uMsg, IntPtr wParam, IntPtr lParam)
             }
             catch (Exception exception)
             {
-                Debug.WriteLine(exception);
+                _logger.Error(exception);
             }
 
             return IntPtr.Zero;
@@ -244,7 +246,7 @@ private bool HandleHotkeyMessage(IntPtr wParam)
             }
             catch (Exception exception)
             {
-                Debug.WriteLine(exception);
+                _logger.Error(exception);
             }
             return processed;
         }

RetailCoder.VBE/Common/WinAPI/RawInput.cs

@@ -1,3 +1,4 @@
+using NLog;
 using System;
 using System.Collections.Generic;
 using System.ComponentModel;
@@ -11,6 +12,7 @@ public class RawInput : NativeWindow
     {
         static readonly Guid DeviceInterfaceHid = new Guid("4D1E55B2-F16F-11CF-88CB-001111000030");
         private readonly List<IRawDevice> _devices;
+        private static readonly Logger _logger = LogManager.GetCurrentClassLogger();
 
         public RawInput(IntPtr parentHandle)
         {
@@ -46,7 +48,7 @@ protected override void WndProc(ref Message message)
                         if (dwSize != res)
                         {
                             var ex = new Win32Exception(Marshal.GetLastWin32Error());
-                            Debug.WriteLine("Error getting the rawinput buffer: {0}", ex.Message);
+                            _logger.Error(ex, "Error getting the rawinput buffer: {0}", ex.Message);
                             return;
                         }
                         foreach (var device in _devices)

RetailCoder.VBE/Inspections/ProcedureCanBeWrittenAsFunctionInspection.cs

@@ -6,11 +6,14 @@
 using Rubberduck.Parsing.Symbols;
 using Rubberduck.Parsing.VBA;
 using System.Diagnostics;
+using NLog;
 
 namespace Rubberduck.Inspections
 {
     public sealed class ProcedureCanBeWrittenAsFunctionInspection : InspectionBase, IParseTreeInspection
     {
+        private static readonly Logger _logger = LogManager.GetCurrentClassLogger();
+
         public ProcedureCanBeWrittenAsFunctionInspection(RubberduckParserState state)
             : base(state, CodeInspectionSeverity.Suggestion)
         {
@@ -26,7 +29,7 @@ public override IEnumerable<InspectionResultBase> GetInspectionResults()
         {
             if (ParseTreeResults == null)
             {
-                Debug.WriteLine("Aborting GetInspectionResults because ParseTree results were not passed");
+                _logger.Debug("Aborting GetInspectionResults because ParseTree results were not passed");
                 return new InspectionResultBase[] { };
             }
             var subStmts = ParseTreeResults.ArgListsWithOneByRefParam

RetailCoder.VBE/Inspections/UntypedFunctionUsageInspection.cs

@@ -43,10 +43,13 @@ public UntypedFunctionUsageInspection(RubberduckParserState state)
         public override IEnumerable<InspectionResultBase> GetInspectionResults()
         {
             var declarations = BuiltInDeclarations
-                    // note: these *should* be functions, but somehow they're not defined as such
-                .Where(item => _tokens.Any(token => (item.IdentifierName == token || item.IdentifierName == "_B_var_" + token)) && item.References.Any());
+                // note: these *should* be functions, but somehow they're not defined as such
+                .Where(item =>
+                        _tokens.Any(token => item.IdentifierName == token || item.IdentifierName == "_B_var_" + token) &&
+                        item.References.Any(reference => _tokens.Contains(reference.IdentifierName)));
 
             return declarations.SelectMany(declaration => declaration.References
+                .Where(item => _tokens.Contains(item.IdentifierName))
                 .Select(item => new UntypedFunctionUsageInspectionResult(this, item)));
         }
     }

RetailCoder.VBE/NLog.dll.nlog

@@ -8,7 +8,7 @@
       name="file"
       fileName="${specialfolder:folder=ApplicationData}/Rubberduck/logs/rubberduck.log"
       layout="${longdate};${uppercase:${level}};${logger};${message};${exception:format=tostring}"
-      archiveFileName="${specialfolder:folder=ApplicationData}/Rubberduck/logs/archives/log.{#####}.log"
+      archiveFileName="${specialfolder:folder=ApplicationData}/Rubberduck/logs/archives/rubberduck.{#}.log"
       archiveAboveSize="5242880"
       archiveNumbering="Sequence"
       concurrentWrites="true"

RetailCoder.VBE/Refactorings/ExtractInterface/ExtractInterfaceRefactoring.cs

@@ -9,6 +9,7 @@
 using Rubberduck.UI;
 using Rubberduck.VBEditor;
 using Rubberduck.VBEditor.Extensions;
+using NLog;
 
 namespace Rubberduck.Refactorings.ExtractInterface
 {
@@ -19,6 +20,7 @@ public class ExtractInterfaceRefactoring : IRefactoring
         private readonly IMessageBox _messageBox;
         private readonly IRefactoringPresenterFactory<ExtractInterfacePresenter> _factory;
         private ExtractInterfaceModel _model;
+        private static readonly Logger _logger = LogManager.GetCurrentClassLogger();
 
         public ExtractInterfaceRefactoring(VBE vbe, RubberduckParserState state, IMessageBox messageBox, IRefactoringPresenterFactory<ExtractInterfacePresenter> factory)
         {
@@ -80,13 +82,13 @@ private void AddInterface()
         private int _insertionLine;
         private void _state_StateChanged(object sender, EventArgs e)
         {
-            Debug.WriteLine("ExtractInterfaceRefactoring handles StateChanged...");
+            _logger.Debug("ExtractInterfaceRefactoring handles StateChanged...");
             if (_state.Status != ParserState.Ready)
             {
                 return;
             }
 
-            Debug.WriteLine("Implementing extracted interface...");
+            _logger.Debug("Implementing extracted interface...");
             var qualifiedSelection = new QualifiedSelection(_model.TargetDeclaration.QualifiedSelection.QualifiedName, new Selection(_insertionLine, 1, _insertionLine, 1));
             _vbe.ActiveCodePane.CodeModule.SetSelection(qualifiedSelection);