Possible command issue with multiple commands at (almost) same time #8

Closed
opened 2017-03-20 00:29:35 +00:00 by jamie · 9 comments
jamie commented 2017-03-20 00:29:35 +00:00 (Migrated from git.hazaar.io)

I have a situation where I am firing off two triggers within a single loop. In this case it is trigger an email to be sent and the loop is through a list of email addresses to send the email to.

The problem is, only first email is being sent because only the first trigger is recognised. I'm not sure if this is a transmission problem on the client, or a receive problem on the server, however the server seems to receive multiple packets at the same time in other situations without a problem.

This is critical, but my current test case was able to work around this issue by putting in a small sleep(1) after sending each trigger.

I have a situation where I am firing off two triggers within a single loop. In this case it is trigger an email to be sent and the loop is through a list of email addresses to send the email to. The problem is, only first email is being sent because only the first trigger is recognised. I'm not sure if this is a transmission problem on the client, or a receive problem on the server, however the server seems to receive multiple packets at the same time in other situations without a problem. This is critical, but my current test case was able to work around this issue by putting in a small ```sleep(1)``` after sending each trigger.
jamie commented 2017-04-01 00:02:15 +00:00 (Migrated from git.hazaar.io)

added ~163 label

added ~163 label
jamie commented 2017-04-01 07:55:14 +00:00 (Migrated from git.hazaar.io)

I have tried to replicate this. At first I failed to replicate it, because it does not appear to be a send issue. It is actually a receive issue. I was able to replicate this issue by putting a standard sleep(1) call inside the event handler. This simulated the sending of email, which does quite a bit of stuff (parses a template, looks up database stuff, talks to sendmail, etc) so the receiver can be hung up for a little while, while it does it's job.

So, I did this to replicate the issue:

class TestService extends \Hazaar\Warlock\Service {

    public function init(){

        $this->subscribe('test_event', 'doTest');

    }

    public function doTest($data){

        sleep(1);

        $this->send('OK', 'DATA: ' . $data);

    }

}

And on the sending side I did this in the index controller:

protected function init() {

        $control = new \Hazaar\Warlock\Control();

        for($i = 0; $i < 5; $i++)
            $control->trigger('test_event', 'Packet #' . $i);

    }

When I did this, I got the first 2 events and then nothing. Log:

2017-04-01 07:48:13 -   INFO - Warlock starting up...
2017-04-01 07:48:14 -   INFO - PHP Version = 7.1.1
2017-04-01 07:48:14 -   INFO - PHP Binary = C:\Program Files (x86)\IIS Express\PHP\v7.1\php.exe
2017-04-01 07:48:14 -   INFO - Application path = D:\Source\example\application
2017-04-01 07:48:14 -   INFO - Application name = example
2017-04-01 07:48:14 -   INFO - Library path = D:\Source\libraries\hazaar-warlock\src
2017-04-01 07:48:14 -   INFO - Application environment = development
2017-04-01 07:48:14 -   INFO - PID = 10044
2017-04-01 07:48:14 -   INFO - PID file = D:\Source\example\application\.runtime\warlock.pid
2017-04-01 07:48:14 -   INFO - Ready for connections...
2017-04-01 07:48:14 -   INFO - Checking for enabled services
2017-04-01 07:48:14 -   INFO - Enabling service: test
2017-04-01 07:48:16 -   INFO - DATA: Packet #0
2017-04-01 07:48:18 -   INFO - DATA: Packet #1

As soon as on the sender I put that sleep back in, I get this:

2017-04-01 07:54:06 -   INFO - Warlock starting up...
2017-04-01 07:54:06 -   INFO - PHP Version = 7.1.1
2017-04-01 07:54:06 -   INFO - PHP Binary = C:\Program Files (x86)\IIS Express\PHP\v7.1\php.exe
2017-04-01 07:54:06 -   INFO - Application path = D:\Source\example\application
2017-04-01 07:54:06 -   INFO - Application name = example
2017-04-01 07:54:06 -   INFO - Library path = D:\Source\libraries\hazaar-warlock\src
2017-04-01 07:54:06 -   INFO - Application environment = development
2017-04-01 07:54:06 -   INFO - PID = 7972
2017-04-01 07:54:06 -   INFO - PID file = D:\Source\example\application\.runtime\warlock.pid
2017-04-01 07:54:06 -   INFO - Ready for connections...
2017-04-01 07:54:06 -   INFO - Checking for enabled services
2017-04-01 07:54:06 -   INFO - Enabling service: test
2017-04-01 07:54:07 -   INFO - DATA: Packet #0
2017-04-01 07:54:09 -   INFO - DATA: Packet #1
2017-04-01 07:54:10 -   INFO - DATA: Packet #2
2017-04-01 07:54:11 -   INFO - DATA: Packet #3

Which is still wrong because i lost the last event. I'm really not sure what is going on here as data should stay in the receive buffer until it is picked up.

Moar testing!

I have tried to replicate this. At first I failed to replicate it, because it does not appear to be a send issue. It is actually a receive issue. I was able to replicate this issue by putting a standard ```sleep(1)``` call inside the event handler. This simulated the sending of email, which does quite a bit of stuff (parses a template, looks up database stuff, talks to sendmail, etc) so the receiver can be hung up for a little while, while it does it's job. So, I did this to replicate the issue: ``` class TestService extends \Hazaar\Warlock\Service { public function init(){ $this->subscribe('test_event', 'doTest'); } public function doTest($data){ sleep(1); $this->send('OK', 'DATA: ' . $data); } } ``` And on the sending side I did this in the index controller: ``` protected function init() { $control = new \Hazaar\Warlock\Control(); for($i = 0; $i < 5; $i++) $control->trigger('test_event', 'Packet #' . $i); } ``` When I did this, I got the first 2 events and then nothing. Log: ``` 2017-04-01 07:48:13 - INFO - Warlock starting up... 2017-04-01 07:48:14 - INFO - PHP Version = 7.1.1 2017-04-01 07:48:14 - INFO - PHP Binary = C:\Program Files (x86)\IIS Express\PHP\v7.1\php.exe 2017-04-01 07:48:14 - INFO - Application path = D:\Source\example\application 2017-04-01 07:48:14 - INFO - Application name = example 2017-04-01 07:48:14 - INFO - Library path = D:\Source\libraries\hazaar-warlock\src 2017-04-01 07:48:14 - INFO - Application environment = development 2017-04-01 07:48:14 - INFO - PID = 10044 2017-04-01 07:48:14 - INFO - PID file = D:\Source\example\application\.runtime\warlock.pid 2017-04-01 07:48:14 - INFO - Ready for connections... 2017-04-01 07:48:14 - INFO - Checking for enabled services 2017-04-01 07:48:14 - INFO - Enabling service: test 2017-04-01 07:48:16 - INFO - DATA: Packet #0 2017-04-01 07:48:18 - INFO - DATA: Packet #1 ``` As soon as on the sender I put that sleep back in, I get this: ``` 2017-04-01 07:54:06 - INFO - Warlock starting up... 2017-04-01 07:54:06 - INFO - PHP Version = 7.1.1 2017-04-01 07:54:06 - INFO - PHP Binary = C:\Program Files (x86)\IIS Express\PHP\v7.1\php.exe 2017-04-01 07:54:06 - INFO - Application path = D:\Source\example\application 2017-04-01 07:54:06 - INFO - Application name = example 2017-04-01 07:54:06 - INFO - Library path = D:\Source\libraries\hazaar-warlock\src 2017-04-01 07:54:06 - INFO - Application environment = development 2017-04-01 07:54:06 - INFO - PID = 7972 2017-04-01 07:54:06 - INFO - PID file = D:\Source\example\application\.runtime\warlock.pid 2017-04-01 07:54:06 - INFO - Ready for connections... 2017-04-01 07:54:06 - INFO - Checking for enabled services 2017-04-01 07:54:06 - INFO - Enabling service: test 2017-04-01 07:54:07 - INFO - DATA: Packet #0 2017-04-01 07:54:09 - INFO - DATA: Packet #1 2017-04-01 07:54:10 - INFO - DATA: Packet #2 2017-04-01 07:54:11 - INFO - DATA: Packet #3 ``` Which is still wrong because i lost the last event. I'm really not sure what is going on here as data should stay in the receive buffer until it is picked up. Moar testing!
jamie commented 2017-06-09 00:43:11 +00:00 (Migrated from git.hazaar.io)
created branch [`8-possible-command-issue-with-multiple-commands-at-almost-same-time`](https://git.hazaarlabs.com/hazaar/hazaar-warlock/compare/master...8-possible-command-issue-with-multiple-commands-at-almost-same-time)
jamie commented 2017-06-09 02:16:52 +00:00 (Migrated from git.hazaar.io)

Note. Packets are NOT getting lost. It looks like the service client only checks for new packets WHILE there are new packets coming in. It then loads them into it's local buffer but if they are not processed they will just sit there until more data arrives.

Note. Packets are NOT getting lost. It looks like the service client only checks for new packets WHILE there are new packets coming in. It then loads them into it's local buffer but if they are not processed they will just sit there until more data arrives.
jamie commented 2017-06-09 02:45:22 +00:00 (Migrated from git.hazaar.io)

Found the issue! Finally! And it was stupid! haha

Basically, when data is received it is converted into a packet. If there is data leftover from the conversion, it is stored in a local frame buffer. However, this frame buffer is only checked when the processFrame() method is called, which is only called when data is received. That's right. THERE IS NO ADDITIONAL FRAME BUFFER CHECK.

I have now added this above the check for new packets from the socket buffer.

Found the issue! Finally! And it was stupid! haha Basically, when data is received it is converted into a packet. If there is data leftover from the conversion, it is stored in a local frame buffer. However, this frame buffer is only checked when the processFrame() method is called, which is only called when data is received. That's right. THERE IS NO ADDITIONAL FRAME BUFFER CHECK. I have now added this above the check for new packets from the socket buffer.
jamie commented 2017-06-09 03:07:31 +00:00 (Migrated from git.hazaar.io)

mentioned in commit 0291dd3bde

mentioned in commit 0291dd3bded00b5c28ef19025008c758072d956f
jamie commented 2017-06-09 03:11:25 +00:00 (Migrated from git.hazaar.io)

mentioned in merge request !3

mentioned in merge request !3
jamie commented 2017-06-09 03:11:33 +00:00 (Migrated from git.hazaar.io)

closed via commit 46832da293

closed via commit 46832da293685efcbb40a27b2e8de0431449977a
jamie commented 2017-06-09 03:11:33 +00:00 (Migrated from git.hazaar.io)

closed via merge request !3

closed via merge request !3
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: hazaar/hazaar-warlock#8
No description provided.