January 13, 2012

Using Log4Net with Visual Lisp

Filed under: AutoCAD,Development — Tags: , , , — Darrin Maidlow @ 1:07 pm

If you’ve worked with me or talked technical with me in the past there is a good chance you area already very aware that I love .  There is also a really good chance that you know I still have a special place in my heart for .  Not only did I spend what may have been the “best years of my life” buried in VLIDE (or hey, maybe all those 30+ hour days and passing out under my desk were the best years of my life? =)) , I still firmly believe that Lisp is one of the most effective way to bang out even a relatively complex operation in AutoCAD when it comes to data manipulation.  ObjectARX (both original and .NET) is great – but the time and effort overhead is pretty high when you just need to bang out a quick routine.

<3 Visual Lisp

Even the quick routines need a little error handling and logging can make a huge difference in documenting the results or diagnosing problems.  Yes, Visual Lisp comes with file I/O calls and I’m sure most of you reading this have rolled your own logging code.  We had some at Kanotech that is still in use for DraftLogic.  Not for long though :=)  Today I’m here to show you how you could bring your Visual Lisp logging into the 21st century.  Not only will it give you – it will let even complex systems that mix technologies (ie. Visual Lisp, ObjectARX .NET) to bring the logging together into a common set of log files.

Overview

There are two sides to this.  First, in .NET we setup Log4Net and expose it to Visual Lisp.  Over on the Lisp side, we’ll load the vlx, setup an error handler, and issue some logging calls.  As usual I’ve attached a Visual Studio solution with sample code.  I’ve also included a compiled dll that you can just go ahead and use.  The attached project is built using .NET 3.5 as this machine only has AutoCAD 2010 installed.  Log4Net itself is built targeting .NET 1.0 so you can modify the .NET runtimes and ObjectARX references used in the attached project and use this code for pretty much any .NET enabled version of AutoCAD/ObjectARX.

In .NET – Setup Log4Net and Lisp Bindings

The Lisp bindings are pretty straight forward.  Expose your call(s) to AutoCAD as a LispFunction.  I’ve built two exposed calls.  One takes two parameters, and uses the value of the first parameter to determine the log type.  The second parameter is the message to log.  The second call is a LogError call that could be used to just log error type messages.  This call could be duplicated for each type of logging state if desired.

 
   1: /// <summary>
   2: /// Lisp exported Log call.  Expects two parameters in lisp.  First the log type which may be either INFO, WARNING, DEBUG, or ERROR.  The second is a string containing the error / message.
   3: /// </summary>
   4: /// <param name="lispArgs"></param>
   5: /// <returns></returns>
   6: /// <remarks>Lisp syntax (Loggit </remarks>
   7: [LispFunction("Loggit")]
   8: public TypedValue Log(ResultBuffer lispArgs)
   9: {
  10:     //Check that we have the correct number of parameters
  11:     Editor ed = Autodesk.AutoCAD.ApplicationServices.Application.DocumentManager.MdiActiveDocument.Editor;
  12:     if (lispArgs == null)
  13:     {
  14:         ed.WriteMessage("\nLoggit - Incorrect number of arguments.  Expected 2 parameters, received none\n");
  15:         return new TypedValue((int)LispDataType.Nil);
  16:     }
  17:     if (lispArgs.AsArray().Length != 2)
  18:     {
  19:         ed.WriteMessage("\nLoggit - Incorrect number of arguments.  Exepected 2 parameters, received " + Convert.ToString(lispArgs.AsArray().Length));
  20:         return new TypedValue((int)LispDataType.Nil);
  21:     }
  22:     
  23:     //params are good.  We expect two strings so rather than test type just convert to string
  24:     String logType = Convert.ToString(lispArgs.AsArray()[0].Value).ToUpper();
  25:     String logMessage = Convert.ToString(lispArgs.AsArray()[1].Value);
  26:  
  27:     switch(logType)
  28:     {
  29:         case "INFO":
  30:             Logger.Current.Info(logMessage);
  31:             break;
  32:         case "WARNING":
  33:         Logger.Current.Warning(logMessage);
  34:             break;
  35:         case "DEBUG":
  36:         Logger.Current.Debug(logMessage);
  37:             break;
  38:         case "ERROR":
  39:             Logger.Current.Error(logMessage);
  40:             break;
  41:     }
  42:     return new TypedValue((int)LispDataType.T_atom);
  43: }
  44:  
  45: //Alternately you could expose individual calls like LogError here.
  46:  
  47: /// <summary>
  48: /// Exposed Lisp function that logs an error directly. Expects a single lisp parameter of type string which is the message to log.
  49: /// </summary>
  50: /// <param name="lispArgs"></param>
  51: /// <returns></returns>
  52: [LispFunction("LogError")]
  53: public TypedValue LogError(ResultBuffer lispArgs)
  54: {
  55:     //Check that we have the correct number of parameters
  56:     Editor ed = Autodesk.AutoCAD.ApplicationServices.Application.DocumentManager.MdiActiveDocument.Editor;
  57:     if (lispArgs == null)
  58:     {
  59:         ed.WriteMessage("\nLoggit - Incorrect number of arguments.  Expected 2 parameters, received none\n");
  60:         return new TypedValue((int)LispDataType.Nil);
  61:     }
  62:  
  63:     String logMessage = Convert.ToString(lispArgs.AsArray()[0].Value);
  64:     Logger.Current.Error(logMessage);
  65:  
  66:     return new TypedValue((int)LispDataType.T_atom);
  67: }

 

One awesome little bit of magic exists in the Logger.cs class.  When configuring the logger it loads the assemblies in question using System.Reflection.  Then it checks in the folder of each loaded dll for the log4net.config file.  This means that logging will only actually log if you have a log4net.config file exists in the same folder as the loaded ObjectARX.NET assembly.  With AutoCAD based extensions this is especially important.  I’ve never liked placing my assemblies (vlx, arx, dll) in the AutoCAD folders.  I’ve always been a huge proponent of extending the AutoCAD search path if needed and using my own directory structures.  This configuration searching technique also eliminates the need for hard coded “here is my log config file” stored in the registry or some other config location. 

Compile that dll and you should be able to run with that in Visual Lisp.

Configure the Logging

As mentioned previously we need to create the configuration file to place with our dll.  There are a couple of lines of code that are quite relevant to get the logging working.  First we have a hard coded configuration file name defined in Logger.cs.  You can customize this if you want.

   1: /// <summary>
   2: /// Name of the file name to search for when trying to configure logging.
   3: /// </summary>
   4: public const string ConfigFileName = "log4net.config";

Next is the name of the logger.  This is quite relevant when configuring your logging.  If this value does not match the value in the config file you will be very frustrated trying to get the logging to fire! If desired change the VisualLisp value to whatever you would like.

   1: /// <summary>
   2: /// This logger name is referenced in the log4net configuration
   3: /// </summary>
   4: private ILog _logImplementation = LogManager.GetLogger("VisualLisp");

Next we have a little bit of XML to slough through.

   1: <?xml version="1.0" encoding="UTF-8"?>
   2: <log4net xmlns="urn:log">
   3:   <appender name="GeneralLog" type="log4net.Appender.FileAppender">
   4:     <file value="VisualLisp.log" />
   5:     <appendToFile value="true" />
   6:     <layout type="log4net.Layout.PatternLayout">
   7:         <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
   8:     </layout>
   9: </appender>
  10:   <logger name="VisualLisp">
  11:     <level value="ALL" />
  12:     <appender-ref ref="GeneralLog" />
  13:   </logger>
  14: </log4net>

This is where things can get crazy!  First the appender section.  This is where you define all the different settings for the actual logging.  I’m running with a standard log file appender, but there are so many choices.  Log to file, log to rolling file, log to database, log to e-mail, log to eventlog, log to almost whatever you want.  You can even write your own custom appenders to log to your toaster oven if you really wanted to.  This is one of the many reasons I <3 Log4Net soooo much.   The basics here are straight forward.  Set the file value=”” to the name and optionally path (either full or relative).  One important note., if you do not specify a full path or you use a relative path the logfile the base point used will be the AutoCAD program files folder.   If you are not running with administrative rights the Vista/Windows 7 file system virtualization will kick in and the log file location will be quite confusing.  It’s probably a good idea to specify a full path here.  More details on some Log4Net configurations can be found on the .

Next take a look at the logger element.  You can define multiple loggers, and each can log to multiple appenders.  Or a single logger can log to multiple appenders.   Note the important value of “Visual Lisp”.  This must match the GetLogger value defined in the private ILog above.  You can also specify which “level” of notice to log.  Though our code may log INFO, WARNING, DEBUG and ERROR calls – if your level is set to ERROR – only the actual error level messages will be logged.

In Visual Lisp – Setup an Error Handler and Issue Logging

So now we have an ObjectARX.NET assembly to load.  We have a handle on configuring our logging.  Here is the contents of the included Lisp file.

   1: ;only load the assembly if it has not been loaded once
   2: (if (not (car (atoms-family 1 '("loggit"))))
   3:     (command "netload" "C:/Users/dmaidlow/Documents/Visual Studio 2010/Projects/Log4Net.VisualLisp/bin/debug/Log4Net.VisualLisp.dll")
   4: )
   5:  
   6: (defun new_ErrorHandler (err)
   7:     (if (or (= (substr err 1 4) "quit")
   8:             (= err "Function cancelled")
   9:         )
  10:         (progn
  11:             ;put any function cancelled logic here
  12:             (princ)
  13:         )
  14:         (progn
  15:             ;an actual error happened here..
  16:             ;you could spew some stuff out to the console, or issue an alert..
  17:             ;(prompt (strcat "\nLisp Returned the following error: \"" st "\"\n"))
  18:             ;(alert (strcat "*ERROR*\nLisp returned the following error: \n\t" st))
  19:  
  20:             ;but we're here to log!
  21:             (Loggit "ERROR" (strcat "An error occurred\n" err))
  22:             
  23:         )
  24:     )
  25:     (gc)
  26:     (princ)
  27: )
  28:  
  29: (setq *error* new_ErrorHandler)
  30: (LogError "Oh No an Error!")
  31: (Loggit "INFO" "This is an informational message")

Not much to it.  To prevent some command line spewage if you load the assembly twice we check first to see if the function has already been exported to the environment.  Here we’ve setup a new error handler that differentiates between a function cancellation and an actual error.  At the bottom you can see a couple of examples of the logging.  If you’ve defined your log4net.config file in the same folder as the assembly if you load this lisp file you will see a log file get created.

Summary

So in review – we’ve exposed Log4Net to the Visual Lisp and command line environment inside of AutoCAD.  This will allow you to unify your logging (if you are already using Log4Net) and may even make you a Log4Net enthusiast as well.  As always I’m always interested in your feedback and constructive criticism!

No Comments »

No comments yet.

RSS feed for comments on this post. TrackBack URL

Leave a comment

Powered by WordPress

Switch to our mobile site