logging attempts to write to /path-to-binary/../log/ ignoring --Init.LogDirectory /tmp

[attila-lendvai]

Describe the bug

this is on Guix (a Linux), where /gnu/store/... is read-only:

$ /gnu/store/ik7k77s5z09axwal7afvxcd6ypqfrfq9-nethermind-binary-1.13.3/bin/Nethermind.Runner --Init.LogDirectory /tmp --datadir /tmp
2022-07-01 09-56-24.5913|Nethermind starting initialization.
2022-07-01 09-56-24.7413|Loading embedded plugins
2022-07-01 09-56-24.7414|  Found plugin type Nethermind.Consensus.AuRa.AuRaPlugin
2022-07-01 09-56-24.7414|  Found plugin type Nethermind.Consensus.Clique.CliquePlugin
2022-07-01 09-56-24.7414|  Found plugin type Nethermind.Consensus.Ethash.EthashPlugin
2022-07-01 09-56-24.7414|  Found plugin type Nethermind.Consensus.Ethash.NethDevPlugin
2022-07-01 09-56-24.7414|  Found plugin type Nethermind.Hive.HivePlugin
Resolved executing directory as /gnu/store/ik7k77s5z09axwal7afvxcd6ypqfrfq9-nethermind-binary-1.13.3/share/nethermind-binary-1.13.3.
2022-07-01 09-56-24.7513|Loading 9 assemblies from /gnu/store/ik7k77s5z09axwal7afvxcd6ypqfrfq9-nethermind-binary-1.13.3/share/nethermind-binary-1.13.3/plugins
2022-07-01 09-56-24.7514|Loading assembly Nethermind.Merge.AuRa
2022-07-01 09-56-24.7538|  Found plugin type Nethermind.Merge.AuRa
2022-07-01 09-56-24.7538|Loading assembly Nethermind.Merge.Plugin
2022-07-01 09-56-24.7570|  Found plugin type Nethermind.Merge.Plugin
2022-07-01 09-56-24.7571|Loading assembly Nethermind.HealthChecks
2022-07-01 09-56-24.7577|  Found plugin type Nethermind.HealthChecks
2022-07-01 09-56-24.7577|Loading assembly Nethermind.AccountAbstraction
2022-07-01 09-56-24.7602|  Found plugin type Nethermind.AccountAbstraction
2022-07-01 09-56-24.7602|Loading assembly Nethermind.Mev
2022-07-01 09-56-24.7615|  Found plugin type Nethermind.Mev
2022-07-01 09-56-24.7615|Loading assembly Nethermind.Init
2022-07-01 09-56-24.7620|Loading assembly Nethermind.Consensus.AuRa
2022-07-01 09-56-24.7644|Loading assembly Nethermind.Api
2022-07-01 09-56-24.7648|Loading assembly Nethermind.EthStats
2022-07-01 09-56-24.7651|  Found plugin type Nethermind.EthStats
2022-07-01 09-56-24.8344|Loading standard NLog.config file from /gnu/store/ik7k77s5z09axwal7afvxcd6ypqfrfq9-nethermind-binary-1.13.3/share/nethermind-binary-1.13.3/NLog.config.
Unhandled exception. System.IO.IOException: Read-only file system : '/gnu/store/ik7k77s5z09axwal7afvxcd6ypqfrfq9-nethermind-binary-1.13.3/share/nethermind-binary-1.13.3/logs'
   at System.IO.FileSystem.CreateDirectory(String fullPath)
   at System.IO.Directory.CreateDirectory(String path)
   at Nethermind.Logging.NLog.NLogManager.SetupLogDirectory(String logDirectory)
   at Nethermind.Logging.NLog.NLogManager..ctor(String logFileName, String logDirectory, String logRules)
   at Nethermind.Runner.Program.GetCriticalLogger()
   at Nethermind.Runner.Program.Main(String[] args)
Aborted

Expected behavior

The logging subsystem only tries to write to what was specified in --Init.LogDirectory.

Please clarify how to proceed, either by updating the docs, or if this is not considered a bug, then by giving some guidance. Thank you!

[tkstanczak]

@AntiD2ta ?

[attila-lendvai]

if this is about logging in a very early phase of the startup, maybe that logger should only log to stderr?

[attila-lendvai]

@AntiD2ta i'm not a CSharp expert, but the issue seems to be that here:

https://github.com/NethermindEth/nethermind/blob/master/src/Nethermind/Nethermind.Runner/Program.cs#L65

a general exception handler is installed that uses GetCriticalLogger, but it's too early in the startup, and here:

https://github.com/NethermindEth/nethermind/blob/master/src/Nethermind/Nethermind.Logging.NLog/NLogManager.cs#L56

GetApplicationResourcePath returns the default, which is relative to the executable?

the following seems to be the first point in the init where the --Init.LogDirectory is first considered:

https://github.com/NethermindEth/nethermind/blob/master/src/Nethermind/Nethermind.Runner/Program.cs#L145

but a lot of logging happens prior to that point in time... maybe all that early logging should strictly only end up printed in the console, not written into the permanent log?

[attila-lendvai]

sorry for pinging this issue... but it would help me a lot if i got at least some general feedback on what to expect.

that way i could either start working towards a workaround on my side, or wait for a fix upstream.

[dceleda]

@smartprogrammer93 , @FalcoXYZ could you help? It seems it got stuck.