log4net does not log from Revit

avpBS7DE · ‎08-24-2021

I am adding `log4net` in my addin.

this is my config.

<?xml version="1.0" encoding="utf-8" ?>
<log4net>
	<root>
		<level value="ALL" />
		<appender-ref ref="console" />
	</root>
	<appender name="console" type="log4net.Appender.ConsoleAppender">
		<layout type="log4net.Layout.PatternLayout">
			<conversionPattern value="%d{yyyy-MM-dd HH:mm:ss} %level %logger - %message%newline" />
		</layout>
	</appender>
</log4net>

this is what I added in the .csproj

	<ItemGroup>
		<PackageReference Include="log4net" Version="2.0.12" />
		<None Include="Config\log4net.config">
			<Link>Config\log4net.config</Link>
			<CopyToOutputDirectory>Always</CopyToOutputDirectory>
		</None>
	<ItemGroup>

this is the code of the eternal command

using UI = Autodesk.Revit.UI;
using DB = Autodesk.Revit.DB;
using RA = Autodesk.Revit.Attributes;

using System.IO;          // Path
using System.Reflection;  // Assembly

using L4N = log4net;
using L4NC = log4net.Config;

namespace MyPlugin{

  public class Logging {
    public static L4N.ILog GetLogger() {
      var dll_dir_info = Directory.GetParent(Assembly.GetExecutingAssembly().Location);
      if (!dll_dir_info.Exists) {
        throw new Exception("dll directory does not exist");
      }
      string log_config_file = Path.Combine(dll_dir_info.FullName, "Config\\log4net.config");
      if (!File.Exists(log_config_file)) {
        throw new Exception("NLog.config does not exist (" + log_config_file + ")");
      }

      var config_stream = new FileInfo(log_config_file);
      L4NC.XmlConfigurator.Configure(config_stream);

     return L4N.LogManager.GetLogger(typeof(Logging));
    }
  }

  [RA.Transaction(RA.TransactionMode.Manual)]
  public class MyButton : UI.IExternalCommand {
    public UI.Result Execute(UI.ExternalCommandData commandData, ref string message, DB.ElementSet elements) {
      var logger = Logging.GetLogger();
      logger.Info("angelo this");
      logger.Debug("angelo that");
        
      return UI.Result.Succeeded;
    }
  }
}

The execution of this code works on a simple C# executable, but when used by a Revit external command it does not print anything.

Same goes for an appender of type RollingFileAppender ....

jeremy_tammik · ‎08-25-2021

Did you look for the previous threads on log4net in this forum?

I checked some of them, and none of them seem to have succeeded in getting this to work. Please check as well.

Are you getting no error message at all?

Are all the required components loading successfully?

Looking at the log4net web site, I see that it is open source:

https://logging.apache.org/log4net

Hence, you should be able to debug right into it and see step by step in the debugger what it is doing.

That should enable you to determine where and what the problem is.

Jeremy Tammik

Developer Advocacy and Support + The Building Coder + Autodesk Developer Network + ADN Open

Revitalizer · ‎08-25-2021

Hi,

your add-in runs in the context of Revit, and Revit has already loaded its own version of Log4Net when your add-in is about to be initialized.

In the installation folder (e.g., "C:\Program Files\Autodesk\Revit 20xx"), you see a "log4net.dll" file.

Just check its version and use this instead of your (newer) one.

Revitalizer

Rudolf Honke
Software Developer
Mensch und Maschine

avpBS7DE · ‎08-25-2021

Hi Jeremy,

thanks for your quick reply. I tried other posts but did not give me the solution to this. I don't have any error msg. It just silently fails to log.

Btw, my example should be plug-and-play (as long as you have a folder called "Config" with "log4net.config" inside). You can try to exectute it outside of Revit (as a .exe with just 3 lines of code, posted below) and it works.

It's not executed only from within Revit.

using System;

using System.IO;          // Path
using System.Reflection;  // Assembly

using L4N = log4net;
using L4NC = log4net.Config;

namespace MyExec {

  class Logging {

    public static L4N.ILog GetLogger() {
      var dll_dir_info = Directory.GetParent(Assembly.GetExecutingAssembly().Location);
      if (!dll_dir_info.Exists) {
        throw new Exception("dll directory does not exist");
      }
      string log_config_file = Path.Combine(dll_dir_info.FullName, "Config\\log4net.config");
      if (!File.Exists(log_config_file)) {
        throw new Exception("NLog.config does not exist (" + log_config_file + ")");
      }

      var config_stream = new FileInfo(log_config_file);
      L4NC.XmlConfigurator.Configure(config_stream);

      return L4N.LogManager.GetLogger(typeof(Program));
    }
  }

  class Program {
    static void Main(string[] args) {
      try {

        var logger = Logging.GetLogger();

        logger.Info("angelo this");
        logger.Debug("angelo that");

      } catch (Exception ex) {
        Console.WriteLine("error: " + ex.Message);
      }
      Console.ReadKey();  // press key to terminate the window
    }
  }
}

avpBS7DE · ‎08-25-2021

Hi Rudolf,

Yes I noticed Revit uses log4net, that's why I used it. At the beginning I had Nlog - with exaclty the same problem of being muted by Revit - so I thought log4net would work .... but no. By the way, have you ever tried NLog from within Revit ? Why are its console (or file) logs also muted suddenly ?

It might be because of a change in version. With my low experience in C'# I am trying to figure this out ...

Until now this was the situation: I was using a more recenly assembly of log4net.

but let's see what happens at runtime. this is process explorer. it shows the assemblies being used by Revit at execution. I push my button from Revit and this is the result:

1. Revit loaded not log4net.dll version 1.2 but log2Plus for its own purposes ... another thing.
2. my assembly of log4net.dll version 2.0 is correctly loaded and used by my button

Revitalizer · ‎08-25-2021

Hi,

Revit uses both native C++ and .Net components, so it needs the C++ variant of Log4Net, too.

I myself use Log4Net ever since in Revit add-ins, but I never use a config file but set the logger's properties in code.

I use a RollingFileAppender but not a console appender.

Revitalizer

Rudolf Honke
Software Developer
Mensch und Maschine

jeremy_tammik · ‎08-25-2021

Hi Rudi,

Congratulations on your solution. That sounds very efficient and clean. Could you possibly share a minimal reproducible case demonstrating haw a Revit add-in can make us of Revit's built-in version of log4net? That would be very helpful in this case, and we could add that as an answer to the other unanswered threads as well, cleaning them all up a bit. Thank you!

Cheers,

Jeremy

Jeremy Tammik

Developer Advocacy and Support + The Building Coder + Autodesk Developer Network + ADN Open

avpBS7DE · ‎08-25-2021

Hi Rudolf,

I tried that inspired by this post. Still does not work.

    public static void SetUpLog4Net() {
      // my own options
      var hierarchy = (L4N.Repository.Hierarchy.Hierarchy)L4N.LogManager.GetRepository();
      {
        var layout = new L4N.Layout.PatternLayout();
        layout.ConversionPattern = "%d{yyyy-MM-dd HH:mm:ss} %level %logger - %message%newline";
        layout.ActivateOptions();

        // on console
        var cons_app = new L4N.Appender.ConsoleAppender();
        {
          cons_app.Target = "Console.Out";
          cons_app.Layout = layout;
        }
        hierarchy.Root.AddAppender(cons_app);

        // on file
        var file_app = new L4N.Appender.RollingFileAppender();
        {
          var dll_dir_info = Directory.GetParent(Assembly.GetExecutingAssembly().Location);
          if (!dll_dir_info.Exists) {
            throw new Exception("dll directory does not exist");
          }
          // same result with relative or absolute path
          file_app.File = Path.Combine(dll_dir_info.FullName, "logs\\angelo.log");  // @"logs\angelo.log";
          Console.WriteLine("set path to " + file_app.File);
          //// would be nice but not needed now
          // file_app.RollingStyle = L4N.Appender.RollingFileAppender.RollingMode.Date;
          // file_app.DatePattern = "yyyyMMdd_HHmmss'_angelo'";
          // file_app.PreserveLogFileNameExtension = true;
          // file_app.StaticLogFileName = false;
          // file_app.AppendToFile = true;
          // file_app.MaxSizeRollBackups = 5;
          // file_app.MaximumFileSize = "10MB";

          file_app.Layout = layout;
        }
        hierarchy.Root.AddAppender(file_app);

        // memory (okay...)
        var memory = new L4N.Appender.MemoryAppender();
        memory.ActivateOptions();
        hierarchy.Root.AddAppender(memory);
      }

      hierarchy.Root.Level = L4N.Core.Level.Info;
      hierarchy.Configured = true;
    }

Followed by its usage

// inside my external command 
SetUpLog4Net();
var logger = L4N.LogManager.GetLogger("OnTheFly");

if (logger.IsDebugEnabled) {
    UI.TaskDialog.Show("debug", "my debug enabled");
    logger.Debug("my debug");
}
if (logger.IsInfoEnabled) {
    UI.TaskDialog.Show("debug", "my info enabled");
    logger.Info("my info");
}
if (logger.IsErrorEnabled) {
    UI.TaskDialog.Show("debug", "my error enabled");
    logger.Info("my error");
}

If you could share your code, I would be glad to take a look.
thank you

Angelo

Revitalizer · ‎08-25-2021

Hi Jeremy,

sure, here is it.

Modify log file path to match one's company and product names.

using log4net;
using log4net.Appender;
using log4net.Config;
using System;
using System.Diagnostics;
using System.IO;
using System.Runtime.CompilerServices;
using System.Text;

namespace SampleName
{
	public static class Logger
	{
		private static ILog mainlogger;

		public static void InitMainLogger(Type type)
		{
			string name = type.ToString();
			var repository = LogManager.CreateRepository(name);
			mainlogger = LogManager.GetLogger(name, type);
			string LogFilePath = Path.Combine(Environment.GetFolderPath(Environment.SpecialFolder.Personal),
				"Company", "Product" + " " + 2022, "Log", "Revit.log");
			RollingFileAppender LogFile = new RollingFileAppender();
			LogFile.File = LogFilePath;
			LogFile.MaxSizeRollBackups = 10;
			LogFile.RollingStyle = RollingFileAppender.RollingMode.Size;
			LogFile.DatePattern = "_dd-MM-yyyy";
			LogFile.MaximumFileSize = "10MB";
			LogFile.ActivateOptions();
			LogFile.AppendToFile = true;
			LogFile.Encoding = Encoding.UTF8;
			LogFile.Layout = new log4net.Layout.XmlLayoutSchemaLog4j();
			LogFile.ActivateOptions();
			BasicConfigurator.Configure(repository, LogFile);
		}

		[MethodImpl(MethodImplOptions.NoInlining)]
		internal static string GetCurrentMethod()
		{
			StackTrace st = new StackTrace();
			StackFrame sf = st.GetFrame(1);
			return sf.GetMethod().Name;
		}

		public static void Log(Exception ex)
		{
			mainlogger?.Error("Error", ex);
		}

		public static void Log(string text, Exception ex)
		{
			mainlogger?.Error(text, ex);
		}

		public static void Log(string text)
		{
			mainlogger?.Info(text);
		}

		public static void Error(string text)
		{
			mainlogger?.Error(text);
		}

		public static void Warn(string text)
		{
			mainlogger?.Warn(text);
		}

		public static void Warn(string text, Exception ex)
		{
			mainlogger?.Warn(text, ex);
		}

		public static void Info(string text)
		{
			mainlogger?.Info(text);
		}
	}
}

In the OnStartup method of the add-in, just initialize it using your add-in's type.

Logger.InitMainLogger(typeof(YourIExternalApplication));

Logger.Log(new Exception("sample exception"));
Logger.Info("just info");

Note that the configuration has a "repository" with a unique name.

If you do not use it this way, your log entries will be shared with other add-ins' loggers that are configured similarly (if they use Log4Net).

That means, without the repository, their logs will be written also to your log file (and vice versa).

Rudi

Rudolf Honke
Software Developer
Mensch und Maschine

avpBS7DE · ‎08-27-2021

Hi Rudi,

I accepted the solution because it did work that way.

This code

PP.Utils.RudiLogger.InitMainLogger(typeof(MyButton));
// PP.Utils.RudiLogger.Log(new Exception("sample exception"));
PP.Utils.RudiLogger.Info("just info");
PP.Utils.RudiLogger.Error("what is going on?!");

Did infact generate that.

<log4j:event logger="MyTab.MyPanel.MyButton" timestamp="1630083899927" level="INFO" thread="1"><log4j:message>just info</log4j:message><log4j:properties><log4j:data name="log4jmachinename" value="DESKTOP-57MDUT6" /><log4j:data name="log4japp" value="DefaultDomain" /><log4j:data name="log4net:UserName" value="DESKTOP-57MDUT6\angel" /><log4j:data name="log4net:Identity" value="" /><log4j:data name="log4net:HostName" value="DESKTOP-57MDUT6" /></log4j:properties></log4j:event>
<log4j:event logger="MyTab.MyPanel.MyButton" timestamp="1630083899942" level="ERROR" thread="1"><log4j:message>what is going on?!</log4j:message><log4j:properties><log4j:data name="log4jmachinename" value="DESKTOP-57MDUT6" /><log4j:data name="log4japp" value="DefaultDomain" /><log4j:data name="log4net:UserName" value="DESKTOP-57MDUT6\angel" /><log4j:data name="log4net:Identity" value="" /><log4j:data name="log4net:HostName" value="DESKTOP-57MDUT6" /></log4j:properties></log4j:event>

Now the questions I am left with are still:
1. Can I print just the text instead of this XML dump ? (I will find out I think)
2. Is there a way to use the logger in Revit from a "log4net.config" file ?
3. Can I print to console ?
The answer to (3) is strangely no. Can you @ru do it ?
I added this code and nothing happened

BasicConfigurator.Configure(repository, logFile); // end of Rudi's code

// from console
var cons_app = new log4net.Appender.ConsoleAppender();
{
    cons_app.Target = "Console.Out";
    cons_app.Layout = new log4net.Layout.XmlLayoutSchemaLog4j();
}
BasicConfigurator.Configure(repository, cons_app);

Thanks and thanks @jeremy_tammik for moderating
Angelo

Revitalizer · ‎08-27-2021

Hi,

personally, I prefer the XML format since it is structured.

Seems that this is what you want, just simple text rows:

https://logging.apache.org/log4net/release/sdk/html/T_log4net_Layout_SimpleLayout.htm

For the second question, I don't know, there was no need to test it, so far.

Print to console: I only know how to write to the 'VS debug' console.

An addin is not a console application, where should the log messages appear?

As far as I understand, you may just want to see the log entries in real-time, in a separate window.

You could do that inside of Revit: in a modeless log dialog or in a log palette.

Or in a separate application that communicates with Revit (Inter Process Communication).

Best regards, have a nice weekend,

Rudi

Rudolf Honke
Software Developer
Mensch und Maschine

jeremy_tammik · ‎08-30-2021

Hi Rudi,

I implemented a sample external command to test this in The Building Coder samples:

https://github.com/jeremytammik/the_building_coder_samples/blob/master/BuildingCoder/BuildingCoder/C...

The log file is created but contains zero bytes:

C:\Users\jta\Documents\Autodesk\TbcSamples\Log>dir

 Directory of C:\Users\jta\Documents\Autodesk\TbcSamples\Log

08/30/2021  05:57 PM                 0 Revit.log
               1 File(s)              0 bytes

Do I need to add some code to flush the file before closing Revit?

Or could something else be the matter?

Jeremy Tammik

Developer Advocacy and Support + The Building Coder + Autodesk Developer Network + ADN Open

Community

log4net does not log from Revit

log4net does not log from Revit

log4net does not log from Revit