jpmens/mqtt-launcher

Script only executed once

Closed this issue · 8 comments

Hi JP
first I would like to thank you for sharing this program!
It works great with the example configuration but not so much with mine.
Here is my configuration:

logfile = 'logfile'
mqtt_broker = '192.168.1.120'       # default: 'localhost'
mqtt_port = 1883                # default: 1883
mqtt_clientid = 'mqtt-launcher-1'
mqtt_username = ''
mqtt_password = ''

topiclist = {

    # topic                     payload value       program & arguments
    "dak/screen"          :   {
                                'off' :   [ '/home/pi/ir_scripts/rpi-hdmi.sh', 'off' ],
                                'on'  :   [ '/home/pi/ir_scripts/rpi-hdmi.sh', 'on'],
                               },
}

I start mqtt-launcher from the command line as user pi.
Then I send (from Node-Red) Topic: dak/screen Payload: on (QoS 2, Retain false) which works ok.
Then I send Topic: dak/screen Payload: off which usually works too (but not always) but then no other commands are accepted. No matter what I send, it is just ignored. Nothing shows up in the log.
But obviously the commands I send are stored somewhere because when I stop mqtt-launcher and start it again, all the previous commands are executed immediately.

2018-02-24 12:16:03,827 Starting
2018-02-24 12:16:03,829 DEBUG MODE
2018-02-24 12:16:03,848 Connected to MQTT broker, subscribing to topics...
2018-02-24 12:16:11,637 dak/screen 2 on
2018-02-24 12:16:11,645 Running t=dak/screen: ['/home/pi/ir_scripts/rpi-hdmi.sh', 'on']
--- This time only one command was executed
2018-02-24 12:18:33,811 Starting
2018-02-24 12:18:33,813 DEBUG MODE
2018-02-24 12:18:33,830 Connected to MQTT broker, subscribing to topics...
2018-02-24 12:18:33,925 dak/screen 2 off
2018-02-24 12:18:33,931 Running t=dak/screen: ['/home/pi/ir_scripts/rpi-hdmi.sh', 'off']
2018-02-24 12:18:34,063 display_power=0
2018-02-24 12:18:34,072 dak/screen 2 on
2018-02-24 12:18:34,075 Running t=dak/screen: ['/home/pi/ir_scripts/rpi-hdmi.sh', 'on']
---After restart all the previously sent commands are executed

Any idea what is going wrong here?

Hermann

Something rings a very vague bell (independently of mqtt-launcher) ... but I cannot grasp it.

Have you verified you don't have another client connected to your broker with the same MQTT clientId? (ClientIDs must be unique on a broker and strange things happen such as the broker kicking one then the other off before they reconnect)

Another thing to check: what version of Mosquitto are you using? Something really old?

Also, make sure you run a mosquitto_sub -h 192.168.1.120 -v -t 'dak/#' against your broker on a 2nd terminal to watch what Node-Red is sending you

Yes I learned about the ClientID the hard way. It took me quite a while to find out that two of my ESP8266 were using the same ID. So this is one of the first things I make sure.
The installation of this Pi Zero is fairly new. I am only running it for about six month. How can you check the version of Mosquitto? I just tried to do an update and got an error message from the Mosquitto repository. Got to check that...

I also made sure that MQTT messages were coming in as they should.

After a few hours of searching I tracked the problem back to this line:

export DISPLAY=:0.0 && kweb -KHJEYPA+-rmfk http://dakboard.com/app?p=b5.... &

This line is starting an instance of kweb browser on the attached monitor.
I have no idea why, but when this line is executed from within my script or from a script started by my script, it brakes the connection between mqtt-launcher (paho?) and mosquitto. When this line is executed after my script is done, everything works. So I made a workaround to execute this line from a cronjob a minute later...

Hermann

I'm not at all familiar with that or with what it does, but that doesn't matter.

If you were doing that from withing the rpi-hdmi script, then what's probably happening is that the controlling tty is being held open; you could try running that with nohup(1).

Nope. Didn't do it.
Nonetheless, thank you for your help.
I'll keep trying.

Hermann

I have exactly the same issue with some commands, but echo works.
If I run the other commands, the first one or two commands run, after that nothing happens anymore, also no new entries in the log file.

I'm on MacOS 10.14.1 (18B75). Python 2.7.15.

Here is my config:

logfile         = 'logfile.log'
mqtt_broker     = '192.168.0.250'       # default: 'localhost'. If using TLS, this must be set to the domain name signed by your TLS certificate.
mqtt_port       = 1883              # default: 1883
mqtt_clientid   = 'mqtt-launcher-mac'
mqtt_username   = 'hassio'
mqtt_password   = 'xxxxxx'
mqtt_tls        = None              # default: No TLS
# mqtt_username = 'jane'
# mqtt_password = 'secret'

topiclist = {

    # topic                     payload value       program & arguments
    "Home/FL/mac"	:   {
                                'sleep'		:   [ 'pmset', 'sleepnow' ],
                                'screen_off'	:   [ 'pmset', 'displaysleepnow' ],
                                'screen_on'	:   [ 'caffeinate', '-u' ],
				'test'		:   [ 'echo', 'Hello' ],
                            },
    "prog/pwd"          :   {
                                None            :   [ 'pwd' ],
                            },
    "dev/1"             :   {
                                None            :   [ 'ls', '-l', '/' ],
                            },
    "dev/2"             :   {
                                None            :   [ "/bin/echo", "111", "*", "@!@", "222", "@!@", "333" ],
                            },
}

Logfile:

2018-12-03 04:12:17,321 Starting
2018-12-03 04:12:17,321 DEBUG MODE
2018-12-03 04:12:17,453 Connected to MQTT broker, subscribing to topics...
2018-12-03 04:12:21,634 Home/FL/mac 0 test
2018-12-03 04:12:21,635 Running t=Home/FL/mac: ['echo', 'Hello']
2018-12-03 04:12:22,804 Home/FL/mac 0 test
2018-12-03 04:12:22,804 Running t=Home/FL/mac: ['echo', 'Hello']
2018-12-03 04:12:23,655 Home/FL/mac 0 test
2018-12-03 04:12:23,656 Running t=Home/FL/mac: ['echo', 'Hello']
2018-12-03 04:12:27,199 Home/FL/mac 0 test
2018-12-03 04:12:27,199 Running t=Home/FL/mac: ['echo', 'Hello']
2018-12-03 04:12:29,218 Home/FL/mac 0 test
2018-12-03 04:12:29,219 Running t=Home/FL/mac: ['echo', 'Hello']
2018-12-03 04:18:07,492 Home/FL/mac 0 test
2018-12-03 04:18:07,492 Running t=Home/FL/mac: ['echo', 'Hello']
2018-12-03 04:21:01,379 Home/FL/mac 0 test
2018-12-03 04:21:01,381 Running t=Home/FL/mac: ['echo', 'Hello']
2018-12-03 04:21:09,361 Home/FL/mac 0 screen_off
2018-12-03 04:21:09,361 Running t=Home/FL/mac: ['pmset', 'displaysleepnow']
2018-12-03 04:21:12,398 Home/FL/mac 0 screen_on
2018-12-03 04:21:12,398 Running t=Home/FL/mac: ['caffeinate', '-u']

mqtt_sub:

Home/FL/mac test
Home/FL/mac/report Hello
Home/FL/mac test
Home/FL/mac/report Hello
Home/FL/mac test
Home/FL/mac/report Hello
Home/FL/mac test
Home/FL/mac/report Hello
Home/FL/mac test
Home/FL/mac/report Hello
Home/FL/mac test
Home/FL/mac/report Hello
Home/FL/mac test
Home/FL/mac/report Hello
Home/FL/mac screen_off
Home/FL/mac/report (null)
Home/FL/mac screen_on

Now the last command Running t=Home/FL/mac: ['caffeinate', '-u'] was run, but there was no corresponding report anymore via mqtt. There must be something happening between executing the command and sending the report via mqtt...

try:
        res = subprocess.check_output(cmd, stdin=None, stderr=subprocess.STDOUT, shell=False, universal_newlines=True, cwd='/tmp')
    except Exception, e:
        res = "*****> %s" % str(e)

the same happens if I format my commands like this "/usr/bin/pmset"

So you are manipulating Mac power with this, am I understanding it correctly? I hope you don't expect me to debug what happens when you change power settings on the fly ...

Please provide a simple example with which I can reproduce the problem.