LCDProc 0.5.4-dev

power_matz

Hello,

I am running the latest version of the driver package installed with the web UI.

The LCDproc server stops after a while setting "thanks for using pfsense" in the display.
Restarting the server works but the the behaviour occures after a while.

I used the version (0.5.3 I think) without any problems.

Is there anyone who is interested in any logfiles (if so, which are of interest?).
If not, where can I get an older version of the package?

Matthias

stephenw10

What LCD do you have? Which driver?
Edit: I see you're using a firebox.
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

marcelloc

@stephenw10:

Here's a suggestion, while reading through some other bootup scripts I found this:
// Do not process while booting
if($g['booting']) 
	exit;
Perhaps we could use this somehow to limit the number of reloads? Of course it could easily stop it loading at all. ::)

Steve

Just some news about this function if still needed.

I found a way to detect and prevent multiple starts during boot.
here is the code I'm including on packages I'm maintaining

	# detect boot process
	if (is_array($_POST)){
		if (preg_match("/\w+/",$_POST['__csrf_magic']))
			unset($boot_process);
		else
			$boot_process="on";
	}

	if(is_process_running("NAME_OF_DAEMON_PROCESS_HERE") && isset($boot_process))
		return;

stephenw10

This looks good. I'll try and test it ASAP. Unfortunately my replacement X-Core has a dead backlight on the LCD. ::)
Hopefully I can combine my two boxes to make one reliable one. :)

Are you including this code in the rc file?

Steve

marcelloc

@stephenw10:

Are you including this code in the rc file?

No, it's on sync function at inc package file.

on postfix.inc for example:

function sync_package_postfix() {
	global $config;

	# detect boot process
	if (is_array($_POST)){
		if (preg_match("/\w+/",$_POST['__csrf_magic']))
			unset($boot_process);
		else
			$boot_process="on";
	}

	if(is_process_running("master") && isset($boot_process))
		return;

	#check patch in /etc/inc/config.
	$relay_domains = "";
	$transport = "";
.
.
.

stephenw10

Still not working. :(
But it does correctly do something.


May 7 18:24:10 	php: : Creating rrd update script
May 7 18:24:11 	php: : Restarting/Starting all packages.
May 7 18:24:11 	php: lcdproc: Sync: Begin package sync
May 7 18:24:12 	php: lcdproc: Sync: End package sync
May 7 18:24:12 	php: : Resyncing OpenVPN instances for interface WAN.
May 7 18:24:12 	php: lcdproc: Sync: Begin package sync
May 7 18:24:12 	php: lcdproc: Sync: End package sync
May 7 18:24:12 	php: : Creating rrd update script
May 7 18:24:12 	php: : The command '/usr/bin/killall 'ntpd'' returned exit code '1', the output was 'killall: warning: kill -TERM 58686: No such process'
May 7 18:24:12 	dnsmasq[47718]: reading /etc/resolv.conf
May 7 18:24:12 	dnsmasq[47718]: using nameserver 192.168.1.1#53
May 7 18:24:12 	dnsmasq[47718]: ignoring nameserver 127.0.0.1 - local interface
May 7 18:24:12 	dnsmasq[47718]: ignoring nameserver 127.0.0.1 - local interface
May 7 18:24:13 	php: : OpenNTPD is starting up.
May 7 18:24:13 	php: : pfSense package system has detected an ip change 0.0.0.0 -> ... Restarting packages.
May 7 18:24:13 	check_reload_status: Starting packages
May 7 18:24:14 	LCDd: LCDd version 0.5.5 starting
May 7 18:24:14 	LCDd: Using Configuration File: /usr/local/etc/LCDd.conf
May 7 18:24:14 	LCDd: Listening for queries on 127.0.0.1:13666
May 7 18:24:14 	php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
May 7 18:24:15 	php: lcdproc: Start client procedure. Error counter: (0)
May 7 18:24:15 	login: login on console as root
May 7 18:24:15 	sshlockout[53881]: sshlockout/webConfigurator v3.0 starting up
May 7 18:24:16 	LCDd: Connect from host 127.0.0.1:26764 on socket 11
May 7 18:24:16 	check_reload_status: Reloading filter
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!
May 7 18:24:21 	LCDd: Client on socket 11 disconnected
May 7 18:24:21 	LCDd: sock_send: socket write error
May 7 18:24:22 	LCDd: Server shutting down on SIGTERM
May 7 18:24:23 	LCDd: LCDd version 0.5.5 starting
May 7 18:24:23 	LCDd: Using Configuration File: /usr/local/etc/LCDd.conf
May 7 18:24:23 	LCDd: sock_create_inet_socket: cannot bind to port 13666 at address 127.0.0.1 - Address already in use
May 7 18:24:23 	LCDd: sock_init: error creating socket - Address already in use
May 7 18:24:23 	LCDd: Critical error while initializing, abort.
May 7 18:24:23 	php: lcdproc: Start client procedure. Error counter: (0)
May 7 18:24:34 	php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
May 7 18:24:34 	php: lcdproc: Start client procedure. Error counter: (1)
May 7 18:24:40 	php: /index.php: Successful webConfigurator login for user 'admin' from 192.168.1.111
May 7 18:24:40 	php: /index.php: Successful webConfigurator login for user 'admin' from 192.168.1.111
May 7 18:24:45 	php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
May 7 18:24:45 	php: lcdproc: Start client procedure. Error counter: (2)
May 7 18:24:56 	php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
May 7 18:24:56 	php: lcdproc: Start client procedure. Error counter: (3)
May 7 18:25:07 	apinger: Error while feeding rrdtool: Broken pipe
May 7 18:25:07 	php: lcdproc: Failed to connect to LCDd process Operation timed out (60)
May 7 18:25:07 	php: lcdproc: Too many errors, the client ends.

It's still hard to get a grip on why this is failing.
The package is initially started and the LCDd daemon successfully connects to the client on socket 11. Then all packages are restarted. For some reason the LCDd instance fails to stop quickly and a new one tries to start but can't because port 13666 is in use. Then the first instance stops and the client times out. :-\

Steve

marcelloc

Try this way:

function sync_package_lcdproc_screens() {
	# detect boot process
		if (is_array($_POST)){
			if (preg_match("/\w+/",$_POST['__csrf_magic']))
				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();
.
.
.

stephenw10

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();
....etc

You 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

marcelloc

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

stephenw10

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

marcelloc

If you want, I can commit the code.

stephenw10

What code are you referring to? Nothing I've tried, and I've tried many variations, has started up correctly. :(

Steve

marcelloc

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();
.

stephenw10

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

marcelloc

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

stephenw10

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:13666

Restarting 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

stephenw10

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.conf

This 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

marcelloc

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

marcelloc

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

stephenw10

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