LCDProc 0.5.4-dev
-
The problem is not that it's syncing multiple times, it's that the package is started and then restarted multiple times.
Adding the boot detection in the sync function cuts this down, since it normally restarts the package after a sync if it's already running, but it's still a problem.Here's the function I'm testing with:
function sync_package_lcdproc_screens() { sync_package_lcdproc(); } function sync_package_lcdproc() { global $g; global $config; global $input_errors; # detect boot process and prevent syncing if (is_array($_POST)){ if (preg_match("/\w+/",$_POST['__csrf_magic'])) unset($boot_process); else $boot_process="on"; } if(is_process_running("LCDd") && isset($boot_process)){ lcdproc_notice("Sync: Still Booting!"); return; } lcdproc_notice("Sync: Begin package sync"); config_lock(); ....etcYou can see it in the logs once for each sync, lcdproc and lcdproc_screens:
May 7 18:24:18 php: : Restarting/Starting all packages. May 7 18:24:18 php: lcdproc: Sync: Still Booting! May 7 18:24:18 php: lcdproc: Sync: Still Booting!However it still goes on to restart lcdproc and for some reason that causes a problem during boot.
Restarting the package at any other time works fine.It would be better to prevent the package restarting during boot but the rc file is a shell script not a php file so I have no idea how that might be done. :-\
Thanks for looking at this.
Steve
-
I've tested the code on a virtual machine, and it started once. It crashed after because there is no lcd display attached.
The sync process for each xml file is called by pfsense during boot, that's why I've configured the code there.
After the sync process, the last step is to call all .sh files in /usr/local/etc/rc.d.Other point is that lcd binary is a php script(all I could see on my teste), so it's quite impossible to determine what php is lcd driver call on current function "is_process_running"
Here is my virtual machine boot log in reverse order.
Check if it starts the way you need.May 7 17:07:07 login: ROOT LOGIN (root) ON ttyv0 May 7 17:07:07 login: ROOT LOGIN (root) ON ttyv0 May 7 17:07:07 login: login on ttyv0 as root May 7 17:07:03 php: lcdproc: Start client procedure. Error counter: (3) May 7 17:07:03 php: lcdproc: Failed to connect to LCDd process Operation timed out (60) May 7 17:06:52 php: lcdproc: Start client procedure. Error counter: (2) May 7 17:06:52 php: lcdproc: Failed to connect to LCDd process Operation timed out (60) May 7 17:06:41 php: lcdproc: Start client procedure. Error counter: (1) May 7 17:06:41 php: lcdproc: Failed to connect to LCDd process Operation timed out (60) May 7 17:06:38 check_reload_status: Reloading filter May 7 17:06:38 Squid_Alarm[7659]: Reconfiguring filter... May 7 17:06:35 Squid_Alarm[63075]: Attempting restart... May 7 17:06:35 Squid_Alarm[62663]: Squid has exited. Reconfiguring filter. May 7 17:06:32 check_reload_status: Reloading filter May 7 20:06:31 squid[59082]: Child (59321) said Child starts May 7 20:06:31 squid[59082]: child (59321) Started May 7 20:06:31 squid[59082]: Platform: FreeBSD,8.1-RELEASE-p6,amd64,-smalloc,-smalloc,-hcritbit May 7 17:06:30 php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing. May 7 17:06:30 php: lcdproc: Start client procedure. Error counter: (0) May 7 17:06:30 LCDd: Critical error while initializing, abort. May 7 17:06:30 LCDd: There is no output driver May 7 17:06:30 LCDd: Could not load driver pyramid May 7 17:06:30 LCDd: Driver [pyramid] init failed, return code -1 May 7 17:06:30 LCDd: pyramid: open(/dev/cuaU0) failed: No such file or directory May 7 17:06:30 LCDd: Listening for queries on 127.0.0.1:13666 May 7 17:06:30 LCDd: Using Configuration File: /usr/local/etc/LCDd.conf May 7 17:06:30 LCDd: LCDd version 0.5.5 starting -
Hmm, not really sure what I'm looking at but it looks like the LCD process is only started once so that's good. ;)
Steve
-
If you want, I can commit the code.
-
What code are you referring to? Nothing I've tried, and I've tried many variations, has started up correctly. :(
Steve
-
did you tested this one?
function sync_package_lcdproc_screens() { sync_package_lcdproc(); } function sync_package_lcdproc() { global $g; global $config; global $input_errors; # detect boot process if (is_array($_POST)){ if ( ! preg_match("/\w+/",$_POST['__csrf_magic'])) return; } lcdproc_notice("Sync: Begin package sync"); config_lock(); . -
I haven't tested that directly but I'm failing to see how it could be any different to the code I did test.
function sync_package_lcdproc_screens() { sync_package_lcdproc(); } function sync_package_lcdproc() { global $g; global $config; global $input_errors; # detect boot process and prevent syncing if (is_array($_POST)){ if (preg_match("/\w+/",$_POST['__csrf_magic'])) unset($boot_process); else $boot_process="on"; } if(is_process_running("LCDd") && isset($boot_process)){ lcdproc_notice("Sync: Still Booting!"); return; }This appears to do it's job correctly.
Unless you have read this entire thread or have been following it let me try to summarise the problem.
The problem is that after at the finish of the boot routine the lcdproc package is not left running in it's normal state. I.e. one instance of LCDd and one instance of lcdproc_client.php.
This problem only occurs with the firebox sdeclcd driver. The problem only appeared when the driver was re-written in order to comply with the rules for having it accepted upstream into lcdroc.
The lcdproc package generates an rc file, lcdproc.sh, in which the start routine is effectively: stop then start. This means that when a restart is called we actually see: stop stop start. There are delays in each of these steps such that it can take an excessive time to complete, longer than the time between restart calls at boot time.
Removing the 'stop then start' feature does not solve this.
The standard package has the result (with your boot detection code preventing even more restarts!) of two instances of LCDd which are both killed and two instances of lcdproc_client one of which survives after boot but then times out.
Changing the rc file to remove the stop call from start results in two instances of LCDd, one of which is correctly left running after boot, and two instances of lcdproc_client but both of these are running after boot! ???
I can only speculate on what might be causing this. A permissions problem? Some of these instances cannot be killed.
A script is running which ends up waiting for part to complete for some reason. When it does complete it then goes on to kill LCDd?The results are different on various fireboxes that have different CPU speed. Scripts complete faster but delays are still in seconds.
It's quite confusing and disappointing. ::)
Steve
-
I saw this part of boot process.
The change from the script you applied to this last one is that it does not check if process is running during boot, it just quit and wait for the final rc.d script to startup lcd driver.
I saw only php process running on my test setup without lcd display.
When you restart the daemon, do you have the LCDd process up and running(ps ax | grep -i lcd)?att,
Marcello Coutinho -
Ah, of course! :-[
Ok I added a notice line so I can see what is happening in the logs:
[code]
function sync_package_lcdproc_screens() {
sync_package_lcdproc();
}
function sync_package_lcdproc() {
global $g;
global $config;
global $input_errors;detect boot process and prevent syncing
if (is_array($_POST)){
if (preg_match("/\w+/",$_POST['__csrf_magic'])){
lcdproc_notice("Sync: Still Booting!");
return;
}
}lcdproc_notice("Sync: Begin package sync");
config_lock();However this doesn't seem to prevent syncing at all.
May 8 11:26:14 php: : Restarting/Starting all packages. May 8 11:26:14 php: lcdproc: Sync: Begin package sync May 8 11:26:14 php: lcdproc: Sync: End package sync May 8 11:26:14 php: lcdproc: Sync: Begin package sync May 8 11:26:14 php: lcdproc: Sync: End package sync May 8 11:26:15 php: : Resyncing OpenVPN instances for interface WAN. May 8 11:26:15 php: : Creating rrd update script May 8 11:26:15 php: : The command '/usr/bin/killall 'ntpd'' returned exit code '1', the output was 'killall: warning: kill -TERM 56507: No such process' May 8 11:26:15 dnsmasq[45442]: reading /etc/resolv.conf May 8 11:26:15 dnsmasq[45442]: using nameserver 192.168.1.1#53 May 8 11:26:15 dnsmasq[45442]: ignoring nameserver 127.0.0.1 - local interface May 8 11:26:15 dnsmasq[45442]: ignoring nameserver 127.0.0.1 - local interface May 8 11:26:16 php: : OpenNTPD is starting up. May 8 11:26:16 php: : pfSense package system has detected an ip change 0.0.0.0 -> ... Restarting packages. May 8 11:26:16 check_reload_status: Starting packages May 8 11:26:17 LCDd: LCDd version 0.5.5 starting May 8 11:26:17 LCDd: Using Configuration File: /usr/local/etc/LCDd.conf May 8 11:26:17 LCDd: Listening for queries on 127.0.0.1:13666 May 8 11:26:17 php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing. May 8 11:26:17 php: lcdproc: Start client procedure. Error counter: (0) May 8 11:26:18 login: login on console as root May 8 11:26:18 sshlockout[53057]: sshlockout/webConfigurator v3.0 starting up May 8 11:26:18 LCDd: Connect from host 127.0.0.1:38259 on socket 11 May 8 11:26:19 check_reload_status: Reloading filter May 8 11:26:21 php: : Restarting/Starting all packages. May 8 11:26:21 php: lcdproc: Sync: Begin package sync May 8 11:26:21 php: lcdproc: Sync: Restarting the service May 8 11:26:21 LCDd: Client on socket 11 disconnected May 8 11:26:21 LCDd: sock_send: socket write error May 8 11:26:21 LCDd: sock_send: socket write error May 8 11:26:21 LCDd: sock_send: socket write error May 8 11:26:23 LCDd: Server shutting down on SIGTERM May 8 11:26:23 php: lcdproc: Sync: End package sync May 8 11:26:23 php: lcdproc: Sync: Begin package sync May 8 11:26:23 php: lcdproc: Sync: Restarting the service May 8 11:26:25 LCDd: LCDd version 0.5.5 starting May 8 11:26:25 LCDd: Using Configuration File: /usr/local/etc/LCDd.conf May 8 11:26:25 LCDd: Listening for queries on 127.0.0.1:13666 May 8 11:26:26 php: lcdproc: Sync: End package sync May 8 11:26:26 LCDd: Server shutting down on SIGTERM May 8 11:26:26 php: lcdproc: Start client procedure. Error counter: (0) May 8 11:26:27 LCDd: LCDd version 0.5.5 starting May 8 11:26:27 LCDd: Using Configuration File: /usr/local/etc/LCDd.conf May 8 11:26:27 LCDd: sock_create_inet_socket: cannot bind to port 13666 at address 127.0.0.1 - Address already in use May 8 11:26:27 LCDd: sock_init: error creating socket - Address already in use May 8 11:26:27 LCDd: Critical error while initializing, abort. May 8 11:26:27 php: lcdproc: Start client procedure. Error counter: (0) May 8 11:26:29 LCDd: LCDd version 0.5.5 starting May 8 11:26:29 LCDd: Using Configuration File: /usr/local/etc/LCDd.conf May 8 11:26:29 LCDd: Listening for queries on 127.0.0.1:13666Restarting the package manually during normal runtime, via the GUI Status: Services: page for example, works fine. Results in 1 LCDd and 1 lcdproc_client.
[2.0.1-RELEASE][root@x-core.localdomain]/root(4): ps aux | grep -i lcd nobody 53996 0.0 0.6 3368 1464 ?? RNs 11:53AM 0:00.04 /usr/local/sbin/LCDd -c /usr/local/etc/LCDd.conf root 54141 0.0 6.9 36188 17004 ?? SN 11:53AM 0:00.33 /usr/local/bin/php -f /usr/local/pkg/lcdproc_client.php [2.0.1-RELEASE][root@x-core.localdomain]/root(5):Hmmm. Steve
-
And here is the other common after boot situation:
[2.0.1-RELEASE][root@x-core.localdomain]/root(1): ps aux|grep -i lcd root 18314 0.0 0.6 3656 1356 ?? IN 12:01PM 0:00.01 /bin/sh /usr/local/etc/rc.d/lcdproc.sh start root 20671 0.0 0.5 3352 1148 ?? IN 12:01PM 0:00.01 /usr/local/sbin/LCDd -c /usr/local/etc/LCDd.conf nobody 20728 0.0 0.6 3368 1408 ?? RNs 12:01PM 0:00.13 /usr/local/sbin/LCDd -c /usr/local/etc/LCDd.confThis is without any boot detection code resulting in the package being restarted 4 times during boot.
The first instance of LCDd you see above has failed to drop it's privileges to 'nobody', it's still running as root. Also this has caused the rc file to get stuck for some reason trying to kill it.
Killing the root instance of LCDd will allow the rc file to finish starting an instance of lcdproc_client.
Steve
-
I'll take a look on this package and see if there is something else to change.
take a look on this fix I've pushed yesterday to pfsense, it may help too.
https://github.com/marcelloc/pfsense/commit/6ae78f0808747893f30b867c51b744dfe39e2190
-
What is the binary for lcdproc?
LCDPROC_SERVICE_NAME is set to lcdproc but starup comand uses LCDd.
LCDd is the server and lcdproc is the client, but I need to understand better how they work.
att,
Marcello Coutinho -
lcdproc works on a server-client basis. The two can be on remote machines if required. The server LCDd runs according to its config file, lcdd.conf, which for use has it listen on localhost:13666.
The client was written in php especially for pfSense, though many other clients are available. The server can connect to several clients at once and will cycle through them sequentially. Hence there are no errors when some instances of lcdproc_client.php are not killed.Both client and server are required.
In the original lcdproc package, written by Seth Mos, the lcdproc_client.php program was run from a separate shell script, lcdclient.sh, but this was removed.
The service name is set to lcdproc but the executable is set to LCDd:
<service><name>lcdproc</name> <rcfile>lcdproc.sh</rcfile> <executable>LCDd</executable> <description>LCD Driver</description></service>Steve
-
Try to apply this patch and use this patched lcdproc.inc file
patch to etc/inc/service-utils.inc that is included on pfsense 2.1 and upcoming 2.0.2
https://github.com/marcelloc/pfsense/commit/6ae78f0808747893f30b867c51b744dfe39e2190patched lcdproc.inc file with some changes on startup process
http://e-sac.siteseguro.ws/packages/lcdproc-dev/lcdproc.inc.txt
you can use fetch -o lcdproc.inc http://e-sac.siteseguro.ws/packages/lcdproc-dev/lcdproc.inc.txt to download the file.diff in patch format
*** backup/lcdproc.inc Tue May 8 12:23:59 2012 --- /usr/local/pkg/lcdproc.inc Tue May 8 12:51:53 2012 *************** *** 72,106 **** if($post['comport']) { switch($post['comport']) { case "none": - continue; - break; case "com1": - continue; - break; case "com2": - continue; - break; case "com1a": - continue; - break; case "com2a": - continue; - break; case "ucom1": - continue; - break; case "ucom2": - continue; - break; case "lpt1": - continue; - break; case "ugen0.2": - continue; - break; case "ugen1.2": - continue; - break; case "ugen2.2": continue; break; --- 72,86 ---- *************** *** 112,143 **** if($post['size']) { switch($post['size']) { case "12x1": - continue; - break; case "12x2": - continue; - break; case "12x4": - continue; - break; case "16x1": - continue; - break; case "16x2": - continue; - break; case "16x4": - continue; - break; case "20x1": - continue; - break; case "20x2": - continue; - break; case "20x4": - continue; - break; case "40x2": continue; break; --- 92,105 ---- *************** *** 149,171 **** if($post['port_speed']) { switch($post['port_speed']) { case "0": - continue; - break; case "1200": - continue; - break; case "2400": - continue; - break; case "9600": - continue; - break; case "19200": - continue; - break; case "57600": - continue; - break; case "115200": continue; break; --- 111,121 ---- *************** *** 185,190 **** --- 135,148 ---- global $g; global $config; global $input_errors; + + # detect boot process + if (is_array($_POST)){ + if (! preg_match("/\w+/",$_POST['__csrf_magic'])) + return; + } + + #continue sync package lcdproc_notice("Sync: Begin package sync"); config_lock(); $lcdproc_config = $config['installedpackages']['lcdproc']['config'][0]; *************** *** 500,516 **** } /* generate rc file start and stop */ $stop = <<<eod<br>! if [ `ps auxw |awk '/lcdproc_client.ph[p]/ {print $2}'| wc -l` != 0 ]; then ! ps auxw |awk '/lcdproc_client.ph[p]/ {print $2}'|xargs /bin/kill ! sleep 1 fi ! if [ `ps auxw |awk '/LCD[d]/ {print $2}'| wc -l` != 0 ]; then ! ps auxw |awk '/LCD[d]/ {print $2}'|xargs /bin/kill sleep 1 fi EOD; $start = $stop ."\n"; ! $start .= "\t/usr/bin/nice -20 /usr/local/sbin/LCDd -c ". LCDPROC_CONFIG ."\n"; $start .= "\t/usr/bin/nice -20 /usr/local/bin/php -f /usr/local/pkg/lcdproc_client.php &\n"; /* write out the configuration */ conf_mount_rw(); --- 458,475 ---- } /* generate rc file start and stop */ $stop = <<<eod<br>! if [ `pgrep -f lcdproc_client.ph` ];then ! pkill -f lcdproc_client.ph ! sleep 1 fi ! if [ `pgrep -anx LCDd` ]; then ! pkill -anx LCDd sleep 1 fi + EOD; $start = $stop ."\n"; ! $start .= "\t/usr/bin/nice -20 /usr/local/sbin/LCDd -c ". LCDPROC_CONFIG ." -u nobody\n"; $start .= "\t/usr/bin/nice -20 /usr/local/bin/php -f /usr/local/pkg/lcdproc_client.php &\n"; /* write out the configuration */ conf_mount_rw();</eod<br></eod<br> -
Ok I've tried that. Replaced lcdproc.inc with your file. Change lines 132, 141 and 150 in service-utils.inc.
Result imediately after boot:[2.0.1-RELEASE][root@x-core.localdomain]/root(1): ps aux|grep -i lcd root 1986 0.0 6.9 36188 16912 ?? SN 9:26PM 0:00.31 /usr/local/bin/php -f /usr/local/pkg/lcdproc_client.phpNo server running. After the boot up sound the display is correct for around 3 seconds and then LCDd is killed.
The system log for that boot shows that it only restarted LCDd twice:May 8 21:26:39 php: : pfSense package system has detected an ip change 0.0.0.0 -> ... Restarting packages. May 8 21:26:39 check_reload_status: Starting packages May 8 21:26:40 LCDd: LCDd version 0.5.5 starting May 8 21:26:40 LCDd: Using Configuration File: /usr/local/etc/LCDd.conf May 8 21:26:40 LCDd: Listening for queries on 127.0.0.1:13666 May 8 21:26:41 php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing. May 8 21:26:41 php: lcdproc: Start client procedure. Error counter: (0) May 8 21:26:42 login: login on console as root May 8 21:26:42 sshlockout[46758]: sshlockout/webConfigurator v3.0 starting up May 8 21:26:42 LCDd: Connect from host 127.0.0.1:10527 on socket 11 May 8 21:26:43 check_reload_status: Reloading filter May 8 21:26:45 php: : Restarting/Starting all packages. May 8 21:26:48 LCDd: Client on socket 11 disconnected May 8 21:26:48 LCDd: sock_send: socket write error May 8 21:26:48 LCDd: Server shutting down on SIGTERM May 8 21:26:49 LCDd: LCDd version 0.5.5 starting May 8 21:26:49 LCDd: Using Configuration File: /usr/local/etc/LCDd.conf May 8 21:26:49 LCDd: sock_create_inet_socket: cannot bind to port 13666 at address 127.0.0.1 - Address already in use May 8 21:26:49 LCDd: sock_init: error creating socket - Address already in use May 8 21:26:49 LCDd: Critical error while initializing, abort. May 8 21:26:50 php: lcdproc: Start client procedure. Error counter: (0) May 8 21:27:01 php: lcdproc: Failed to connect to LCDd process Operation timed out (60) May 8 21:27:01 php: lcdproc: Start client procedure. Error counter: (1) May 8 21:27:09 sshd[2220]: Accepted keyboard-interactive/pam for root from 192.168.1.111 port 51742 ssh2 May 8 21:27:12 php: lcdproc: Failed to connect to LCDd process Operation timed out (60) May 8 21:27:12 php: lcdproc: Start client procedure. Error counter: (2) May 8 21:27:23 php: lcdproc: Failed to connect to LCDd process Operation timed out (60) May 8 21:27:23 php: lcdproc: Start client procedure. Error counter: (3) May 8 21:27:33 apinger: Error while feeding rrdtool: Broken pipe May 8 21:27:34 php: lcdproc: Failed to connect to LCDd process Operation timed out (60) May 8 21:27:34 php: lcdproc: Too many errors, the client ends. May 8 21:28:33 apinger: /usr/local/bin/rrdtool respawning too fast, waiting 300s. May 8 21:30:41 check_reload_status: Linkup starting re2Result: no change! ???
Steve
-
php: : pfSense package system has detected an ip change 0.0.0.0 -> … Restarting packages.
This maybe the cause.
It's forcing all packages to restart.I'll check the startup script again.
att,
Marcello Coutinho -
Additionally the boot detection is now working so well that it inhibits all syncing at start up.
That prevented the new rc file being written out. I synced it manually. Still no change! ::)My thoughts are that it should be able to cope with this. Other packages don't have a problem being restarted multiple times. Also running LCDd with other drivers is no problem.
It seems more like LCDd cannot close correctly causing:May 8 21:50:30 LCDd: sock_init: error creating socket - Address already in use May 8 21:50:30 LCDd: Critical error while initializing, abort.Again I really appreciate you looking at this.
Steve -
I have seen this behaviour at start up but not during normal running. Does it coincide with an IP change or an interface going up or down, when packages are restarted?
The old firebox lcd driver, which was 0.52 then 0.53, was not a pfSense package and as such it was only ever started once at boot. Currently there is an unresolved issue with the package being restarted multiple times during boot. This seems cause a problem with LCDd which cannot start/stop fast enough. On my box the daemon/client often ends up running incorrectly but after restarting manually it runs fine until I next reboot the box.
Steve
Hello Steve,
it seems that the IP change at night might cause the LCDproc to stop.
But after manually starting the LCDproc it shows sometime the info in the LCD panel CLI:0 SRV:0. And nothing more happen.Can I change some config file to prevent the behaviour to stop at IP change?
Matthias
-
There is an issue with the firebox driver and the startup procedure with the lcdproc-dev package. See my posts above this. Hopefully we can get to the cause of this soon.
When you see 'CLI:0 SRV:0' on the LCD it's because the server, LCDd, is running but the client, lcdproc_client.php, is not.
Which firebox do you have?Steve
-
There is an issue with the firebox driver and the startup procedure with the lcdproc-dev package. See my posts above this. Hopefully we can get to the cause of this soon.
When you see 'CLI:0 SRV:0' on the LCD it's because the server, LCDd, is running but the client, lcdproc_client.php, is not.
Which firebox do you have?Steve
Hi Steve,
I have a Firebox X750 showing this effect.
But yesterday I switched to my backup firebox X700 ;-). And there is not such a behaviour. It runs like a charm… with the same config.
After the nightly IP switch the LCDproc is still running cycling thru the different screens.
Maybe it depends on the X750 model?Matthias
