jbroadway/analog

Could not lock file

trasher opened this issue · 5 comments

Hello, I'm sometimes throwing the following error:
exception 'RuntimeException' with message 'Could not lock file' in /home/travis/build/galette/galette/galette/includes/Analog-1.0.0.git876d8a3bb/Analog/Handler/File.php:27

That file should not be locked, it is used by Analog only.

I do not know how to reproduce it, I had it a very few times using my application; but that regulary fail on my travis unit tests.

Of course, I could disable file logging during tests to avoid that; but I'm afraid my users may throw the same issue on some configurations.

Any idea how to fix that?

I would try setting the file manually via:

Analog::handler (\Analog\Handler\File::init ('my_log_file.txt'));

The lock is in place since concurrent requests may try to write to the file at the same time. It's strange that the lock gives you trouble on travis-ci since that's never given me an issue on there...

https://travis-ci.org/jbroadway/analog/builds

If that doesn't do it, you can always create a custom handler based on the File handler that removes the locking.

When there are two many requests to access the same file, it throws a lock error because LOCK_NB is specified in line 26 of analog/lib/Analog/Handler/File.php. Remove that like below and it should block while trying to lock the file.

                    if (! flock ($f, LOCK_EX)) {
                            throw new \RuntimeException ('Could not lock file');
                    }

@jbroadway I'm already using the code you give to init the file handler, excepting it is part of a multi handler, using something like this:

$run_log = \Analog\Handler\File::init($log_path);
$null_log = \Analog\Handler\Null::init();
Analog::handler(
    \Analog\Handler\Multi::init(
        array (
            Analog::URGENT      => $run_log,
            Analog::ALERT       => $run_log,
            Analog::CRITICAL    => $run_log,
            Analog::ERROR       => $run_log,
            Analog::WARNING     => $null_log,
            Analog::NOTICE      => $null_log,
            Analog::INFO        => $null_log,
            Analog::DEBUG       => $null_log
        )
    )
);

@mta59066 thank you for the pointer :) I guess I should use that in a custom handler based on File one.

I guess I should also disable logging for my unit tests; logging is much more useful for the users who do not have access to syslogs in production environments.

In "normal" conditions, I should not have so many requests to the logger in a few seconds; and I never ran into that issue; running the test that did not happen every time anyway :/

I'll double check my logs call to see if one of them is not called "too frequently".

Thank you :)

Looking into LOCK_NB more closely, I believe @mta59066's suggestion to remove it should become the default case. The log file won't be locked for more than a few milliseconds, so blocking isn't really an issue, and we do want to ensure that messages do arrive as expected. Will fix it momentarily.

Thanks for exposing this issue! :)

Great, thank you very much @jbroadway and @mta59066 :-)