Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

what happens if a loop is still executing when the interval comes up? #15

Closed
davetbo opened this issue May 24, 2018 · 6 comments
Closed

Comments

@davetbo
Copy link

davetbo commented May 24, 2018

I think this is what happens:
2018-05-24 00:34:19.3006: 12023 12023: DEBUG: Daemon::wait: Loop took too long. [Interval=10.000000] [Duration=10.245913] [Extra=0.245913]

This comes up in my logs. I'm wondering how the program behaves in this instance? Do I need to make sure that my interval is set long enough that the job can't possibly be running, or will it just gracefully skip the next iteration if the last one is still running?

Thanks,
Dave

@phuze
Copy link

phuze commented May 24, 2018

Are you using a task or a worker?

Can you please post some code so we can see what you're trying to do. Also, please post code using the insert code button or by using three ```

I get the sense you're jamming all your code into the main execute loop. Am I correct? You should be using workers or tasks. For example, my execute function simply looks like:

protected function execute()
{

    if ($this->getLoopIterations() % 5 == 0) {
        $this->task('CsvProcess');
    }

    # broadcast a heartbeat every 2 minutes
    if ($this->getLoopIterations() % 120 == 0) {
        Logger::heartbeat("DAEMON-CSV   [".getmypid()."]");
    }

}

My interval ticks every 1 second.

The idea, is that your main daemon logic (execute() function) is called every interval (as defined in run.php). Your execute function should in turn, call a task or a worker which then handles the majority of your application logic. Each task or worker is spawned as its own process and terminates when your code logic does.

@davetbo
Copy link
Author

davetbo commented May 24, 2018

Here's a test of a long loop that throws that same error.


require __DIR__ . '/../vendor/autoload.php';

use Lifo\Daemon\Daemon;
use Lifo\Daemon\Event\DaemonEvent;
use Lifo\Daemon\Event\SignalEvent;

class QuickStartDaemon extends Daemon
{
    
    protected function initialize()
    {
        // add the FileLock plugin. Does not allow a second QuickStartDaemon from running
        $this->addPlugin('Lifo\Daemon\Plugin\Lock\FileLock', [
            // if the lock isn't updated within X seconds, then other QuickStartDaemon processes will see it as stale
            'ttl'  => 10,
            'file' => '/tmp/quick_start_daemon.pid',
        ]);
        
    }
    
    protected function execute()
    {
        sleep(10);
    }
    
    protected function onShutdown()
    {
        $this->log("OH NO!!! we're shutting down! I better do some clean up");
        // do stuff here...
    }
}

declare(ticks = 1); // needed for signal handling

QuickStartDaemon::getInstance()
  ->setDaemonize(false) 
  ->setLoopInterval(5)
  ->setVerbose(true)
  ->setDebug(true)
  ->setDebugLevel(3)
  ->setLogFile('/tmp/quick_start_daemon.log')
  ->run(); 

I force the situation by making execute sleep 10 but loop interval be 5. When I run this, I see this debug warning:
DEBUG: Daemon::wait: Loop took too long. [Interval=5.000000] [Duration=10.000357] [Extra=5.000357]

I'm just wondering how the program handles the situation when a long loop occurs. Does it somehow break successive loops, does it run them concurrently and they overlap somehow, or does it just skip the one that would have stepped on the already-going one? I would think just skipping the one while the previous is still running might be best, but you've though through this stuff more than I have, so I'm just wondering what I can expect from your code when this happens.

Best,
Dave

@davetbo
Copy link
Author

davetbo commented May 24, 2018

I see what you're saying about workers or tasks, now. Specifically, somewhere I just read that execute should exit as quickly as possible after spawning off all the subprocesses. I will get this part working and then see if I still have the same issue with my testing code (the other issue I just submitted). We can put the other one on hold for a bit.

Also, I see what you're saying about the spawning of separate tasks or sub-processes. The answer, I think, is that your execute will spawn another task even if the one from the previous interval is running, right?

Best,
Dave

@phuze
Copy link

phuze commented May 24, 2018

Also, I see what you're saying about the spawning of separate tasks or sub-processes. The answer, I think, is that your execute will spawn another task even if the one from the previous interval is running, right?

Correct.

@lifo101
Copy link
Owner

lifo101 commented May 25, 2018

What is your main Daemon loop doing? The main Daemon::execute() call should be as quick as possible. Essentially, your execute() will check a resource (eg: a DB connection, a web socket, etc) and if nothing is pending, then return and wait for the next iteration. If your execute() takes too long, it can cause problems with Process Management. It'll cause forked children to not be culled in a timely manner and will slow down your entire Daemon.

If your resource polling does see something to act on, it should record that event, and fire off a worker to handle it, and then return from execute().

Either way, your main main execute() method shouldn't be sticking around for 10 seconds. If it is, you need to re-think what you're doing. Writing multi-process programs takes a different approach then a stand alone program.

To re-iterate:

  1. Daemon::execute() is called
  2. Check for new incoming events. You generally check once, or for a very small amount of time.
  3. Call a Worker method to handle the pending event.
  4. Return from the execute() method.

BTW, the warning you're seeing in your logs about the loop taking too long is just a notification that you're probably doing something wrong, or something is broken in your Daemon. The next loop iteration will be triggered immediately after that message appears in the logs.

@davetbo
Copy link
Author

davetbo commented May 29, 2018 via email

@lifo101 lifo101 closed this as completed May 29, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants