start_with_specfile doesn't allow multiple instances of the program

[ashaduri]

Hi,

My program uses flexi_logger with a specfile. But, if I launch 2 instances in parallel, the second one does not enable logging and fails with: "Filesystem notifications for the specfile could not be set up".

I think it should be possible to run 2 instances with the same configuration without specfile filesystem notifications. Perhaps add an option to disable the "automatic reloading at runtime" feature?

Thanks!

[emabee]

Strange. Which platform do you use? Can you provide more details on the error?

[ashaduri]

The platform is OpenSUSE Linux 15.0, kernel 4.12.14-lp150.12.82-default, x86_64, rust 1.44.1.

This is a (slightly modified) original code:

// Try creating a logger with config_log.toml
let config_file_logger = flexi_logger::Logger::with_str("info")
		.build_with_specfile("config_log.toml");
match config_file_logger {
	Ok((logger, _handle)) => {
		loggers.push(logger);
	},
	Err(error) => {
		// This usually fails due to config file locking error, when running a second instance.
		println!("Could not set up flexi_logger: {}", error);
	},
};

This is the error I get:
Could not set up flexi_logger: Filesystem notifications for the specfile could not be set up

[emabee]

Is the failure occuring only if the specfile did not exist before starting the executables? Does the Debug-print of the error provide some more info? The error String shown is only used by FlexiLoggerError::SpecfileNotify, which has as source error a notify::Error, which should provide some additional information.

[ashaduri]

The specfile always exists, in both instances. It's the same source tree, I'm just doing "cargo run" from 2 terminal windows.

The debug output:
Could not set up flexi_logger: SpecfileNotify(Io(Os { code: 9, kind: Other, message: "Bad file descriptor" }))

[emabee]

Code 9 says
#define EBADF 9 /* Bad file number */
and could occur e.g. if you open a file for reading and then try to write, or maybe also if two processes access the same file not only for reading.
But the only occasion where flexi_logger writes the file is when the file does not exist when flexi_logger is being initialized, then the file is created.
Is your cargo build interfering with the specfile?
Can you reproduce the issue if you start the executable directly, rather than by using cargo run?

[ashaduri]

Is your cargo build interfering with the specfile?

No, not at all.

Can you reproduce the issue if you start the executable directly, rather than by using cargo run?

Yes.

I also don't see config_log.toml in lsof output.
I can read/write the config file without errors while the first instance is running.

I also tried changing the config filename to "config_log2.toml". The first instance created it during launch, the second instance gave me the same error.

[emabee]

I can't reproduce so far, neither on Windows, nor on Suse 12.2.

I tried with a main with this body:

    flexi_logger::Logger::with_str("info").start_with_specfile("config_log.toml").unwrap();

    log::info!("Starting");
    log::trace!("Should not be seen");

    std::thread::sleep(std::time::Duration::from_secs(10));

    log::trace!("Tracing works!!");
    log::info!("Terminating");

which gave me some time to modify the specfile after starting, and verify both were reacting.

What version of flexi_logger do you use?
Do you use notify directly, too?

[ashaduri]

Hi, the version I was using was 0.15.8, I updated cargo.toml to use 0.5.10.
I don't use notify directly.

OK so I did some additional testing with your code above and mine.
The first time I tried your code it failed with "Bad file descriptor". Then mine started failing as well, even the first instance.
A reboot solved it.

However, I have rebooted a few times after I first encountered this problem, and it always reappears, so it looks to me that once the system is loaded properly (many files open in IDEs, etc...) and running for some time, there is some kind of resource starvation situation related to notify. I would expect a different error message but maybe there is a bug in kernel that causes "Bad file descriptor" instead of ENOSPC or similar.

Is it possible to add API to simply disable notify (perhaps a cargo feature)? Or, perhaps, add a flag that doesn't cause complete failure if notify is failing? In my application there is absolutely no need for this - actually, I'd rather not have any file monitoring for security.

Thanks!

[emabee]

Is it possible to add API to simply disable notify (perhaps a cargo feature)?
Yes, I see the point, and will provide an option.

For the time being, you could use LogSpecification::from_toml() and Logger::with(logspec: LogSpecification) and finally Logger::start() \ Logger::build() rather than the _with_specfile variants as a workaround.

[ashaduri]

Thanks! I really appreciate it!

[emabee]

You can now use feature specfile_without_notification instead of specfile to disable the notify usage (and benefit).