Zend Expressive - Swoole - Hot Code Reload

@matthew

Good morning

When enabling hot code reload, I get a warning when changing a file:

[2019-02-26 01:46:38 *15384.0]  WARNING swSignalfd_onSignal (ERROR 707): Unable to find callback function for signal User defined signal 1: 10.

Environment

zendframework/zend-expressive                   3.2.1
zendframework/zend-expressive-swoole            2.3.0

Distributor ID: Debian
Description:    Debian GNU/Linux 9.7 (stretch)
Release:        9.7
Codename:       stretch

PHP 7.3.2-3+0~20190208150725.31+stretch~1.gbp0912bd (cli) (built: Feb  8 2019 15:07:25) ( NTS )
Copyright (c) 1997-2018 The PHP Group
Zend Engine v3.3.2, Copyright (c) 1998-2018 Zend Technologies

swoole

Swoole => enabled
Author => Swoole Team <team@swoole.com>
Version => 4.2.13
Built => Feb 25 2019 10:11:00
coroutine => enabled
epoll => enabled
eventfd => enabled
signalfd => enabled
cpu_affinity => enabled
spinlock => enabled
rwlock => enabled
sockets => enabled
openssl => OpenSSL 1.1.1a  20 Nov 2018
http2 => 1.18.1
pcre => enabled
zlib => enabled
mutex_timedlock => enabled
pthread_barrier => enabled
futex => enabled
mysqlnd => enabled
async_redis => enabled

Directive => Local Value => Master Value
swoole.display_errors => On => On
swoole.enable_coroutine => On => On
swoole.fast_serialize => Off => Off
swoole.unixsock_buffer_size => 8388608 => 8388608
swoole.use_shortname => On => On

inotify

Version => 2.0.0

Would you please try setting/changing zend-expressive-swoole > swoole-http-server > mode to SWOOLE_PROCESS?
I just noticed instances of errors (albeit different ones) when using hot code reload with mode set to SWOOLE_BASE and no more than 1 worker.

1 Like

Well, when setting the mode to SWOOLE_PROCESS, I do not longer receive the warning and the workers are reloaded as expected, even with only one worker but… read below…

File changed /github/i-MSCP/imscp/frontend/src/Account/src/Handler/Admin/AddResellerHandler.php, reloading
[2019-02-26 12:32:38 $18686.0]  NOTICE  Server is reloading all workers now.
Worker started in /github/i-MSCP/imscp/frontend with ID 0

Note that before switching to SWOOLE_PROCESS the following warning was also raised on start:

[2019-02-26 12:16:49 $17040.0]  WARNING swReactorProcess_start: The onStart event with SWOOLE_BASE is deprecated.

Anyway, the hot code reload seem a bit useless… For instance, if I modify the handler mentionned in the log above twice, the first time, it will cause a reload but subsequent modification will not trigger a reload… That look like a bug for me. This issue arise with one or many workers… With many workers, the issue is more hard to catch…

BTW:

'zend-expressive-swoole' => [
    'enable_coroutine' => true,
    'hot-code-reload' => [
        // Set to true to enable hot code reload; the default is false.
        'enable' => true,
    
        // Time in milliseconds between checks to changes in files.
        'interval' => 500,
    ],
    'swoole-http-server' => [
        'enable_coroutine' => true,
        'process-name' => 'imscp-frontend',
        'mode' => SWOOLE_PROCESS
    ]
    
]

Glad it works now! I think this limitation should be documented though.

That is actually a feature! Only files which were loaded by PHP since the last swoole start/reload will cause a reload when changed.
Example:

  1. GET /reseller, ResellerHandler.php is loaded
  2. Change ResellerHandler.php, this triggers a reload
  3. Change ResellerHandler.php again, this will not trigger a reload
  4. GET /reseller, the latest ResellerHandler.php is loaded, so the latest changes are displayed

Really? Well… When developing, I expect the following behavior:

  1. GET /reseller, ResellerHandler.php is loaded
  2. Change ResellerHandler.php, this triggers a reload
  3. GET /reseller, the latest ResellerHandler.php is loaded
  4. Change ResellerHandler.php, this triggers a reload
  5. GET /reseller, the latest ResellerHandler.php is loaded

Problem, for now I get:

  1. GET /reseller, ResellerHandler.php is loaded
  2. Change ResellerHandler.php, this triggers a reload
  3. GET /reseller, the latest ResellerHandler.php is loaded
  4. Change ResellerHandler.php, this doesn’t triggers a reload
  5. GET /reseller, the latest ResellerHandler.php isn’t loaded

You see the problem for development time?

Ah, I see, you’re right, this is a problem, only happens when using multiple workers though, since only worker#0 is actively scanning for file changes in the files loaded by itself, not the ones loaded by the others.

To fix it, I suggest changing the hot-code-reload implementation in zend-expressive-swoole library so that the reloader runs in all workers (I can provide a PR for this).

In the meanwhile, as a workaround, using only 1 worker in development environment should produce the expected behavior:

1 Like

There is the same problem with only one worker :wink:

Was not able to reproduce it, can you provide a test-case?

What do you mena by test case exactly?

Full log
nuxwin@dev:/github/i-MSCP/imscp/frontend$ IMSCP_MASTER_CONFFILE=/github/i-MSCP/imscp/stamp/imscp.conf IMSCP_DB_PLAIN_PASSWORD=1 php ./vendor/bin/zend-expressive-swoole start -w 1
Swoole is running at 127.0.0.1:8080, in /github/i-MSCP/imscp/frontend
Worker started in /github/i-MSCP/imscp/frontend with ID 0
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /admin/account/add/reseller HTTP/1.1” 200 7341
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/css/jquery-ui-black.css?v=1543532764 HTTP/1.1” 200 37206
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/css/ui.css?v=1551003732 HTTP/1.1” 200 25886
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/css/black.css?v=1546925144 HTTP/1.1” 200 4962
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/js/jquery/jquery.js?v=1543532764 HTTP/1.1” 200 95786
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/js/jquery/jquery-ui.js?v=1543532764 HTTP/1.1” 200 238314
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/js/jquery/plugins/dataTables.js?v=1543532764 HTTP/1.1” 200 77499
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/js/jquery/plugins/dataTables_naturalSorting.js?v=1543532764 HTTP/1.1” 200 3633
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/js/jquery/plugins/pGenerator.js?v=1543532764 HTTP/1.1” 200 5158
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/js/imscp.js?v=1550984618 HTTP/1.1” 200 21589
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/isp/logo/isp_logo.png HTTP/1.1” 404 1718
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/background/left_bg.jpg HTTP/1.1” 200 472
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/background/top_bg.jpg HTTP/1.1” 200 406
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/background/mainmenu_left.png HTTP/1.1” 200 240
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/background/mainmenu_bg.png HTTP/1.1” 200 126
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/menu/general.png HTTP/1.1” 200 2118
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/menu/manage_users_a.png HTTP/1.1” 200 2176
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/menu/custom_link.png HTTP/1.1” 200 3535
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/background/top_left_bg.jpg HTTP/1.1” 200 25857
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/jquery-ui/ui-bg_glass_40_000000_1x400.png HTTP/1.1” 200 259
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/menu/manage_users.png HTTP/1.1” 200 2232
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/user/logout.png HTTP/1.1” 200 869
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/background/left_top_bg.jpg HTTP/1.1” 200 11590
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/background/bullet.png HTTP/1.1” 200 177
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/jquery-ui-common/ui-bg_flat_0_ffffff_40x100.png HTTP/1.1” 200 208
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/content/table_icon_user_blue.png HTTP/1.1” 200 1432
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/black/background/bullet_hover.png HTTP/1.1” 200 177
127.0.0.1 - - [26/Feb/2019:14:01:54 +0100] “GET /asset/default/images/favicon.ico?v=1543532764 HTTP/1.1” 200 1150
File changed /github/i-MSCP/imscp/frontend/src/Account/src/Handler/Admin/AddResellerHandler.php, reloading
[2019-02-26 14:01:57 $24071.0] NOTICE Server is reloading all workers now.
Worker started in /github/i-MSCP/imscp/frontend with ID 0
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /admin/account/add/reseller HTTP/1.1” 200 7341
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/css/jquery-ui-black.css?v=1543532764 HTTP/1.1” 200 37206
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/css/ui.css?v=1551003732 HTTP/1.1” 200 25886
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/css/black.css?v=1546925144 HTTP/1.1” 200 4962
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/js/jquery/jquery.js?v=1543532764 HTTP/1.1” 200 95786
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/js/jquery/jquery-ui.js?v=1543532764 HTTP/1.1” 200 238314
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/js/jquery/plugins/dataTables.js?v=1543532764 HTTP/1.1” 200 77499
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/js/jquery/plugins/dataTables_naturalSorting.js?v=1543532764 HTTP/1.1” 200 3633
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/js/jquery/plugins/pGenerator.js?v=1543532764 HTTP/1.1” 200 5158
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/js/imscp.js?v=1550984618 HTTP/1.1” 200 21589
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/isp/logo/isp_logo.png HTTP/1.1” 404 1718
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/background/left_bg.jpg HTTP/1.1” 200 472
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/background/top_bg.jpg HTTP/1.1” 200 406
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/background/mainmenu_left.png HTTP/1.1” 200 240
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/background/mainmenu_bg.png HTTP/1.1” 200 126
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/menu/general.png HTTP/1.1” 200 2118
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/menu/manage_users_a.png HTTP/1.1” 200 2176
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/menu/custom_link.png HTTP/1.1” 200 3535
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/background/top_left_bg.jpg HTTP/1.1” 200 25857
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/jquery-ui/ui-bg_glass_40_000000_1x400.png HTTP/1.1” 200 259
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/menu/manage_users.png HTTP/1.1” 200 2232
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/user/logout.png HTTP/1.1” 200 869
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/background/left_top_bg.jpg HTTP/1.1” 200 11590
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/background/bullet.png HTTP/1.1” 200 177
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/black/background/bullet_hover.png HTTP/1.1” 200 177
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/content/table_icon_user_blue.png HTTP/1.1” 200 1432
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/jquery-ui-common/ui-bg_flat_0_ffffff_40x100.png HTTP/1.1” 200 208
127.0.0.1 - - [26/Feb/2019:14:02:00 +0100] “GET /asset/default/images/favicon.ico?v=1543532764 HTTP/1.1” 200 1150

Then once after, change to the handler never trigger a reload again…