Pluginstay in ''runing'' state when has been shut down.

[Guest]

I am shutthing hs3 down with

systemctl stop hs3.service

But mcsmqtt stay up every time. I don't know since when this behavior started.

I am using the very last version of mcsmqtt , on a x64 Linux ubuntu box. Last stable version of mono too.

[Michael McSharry]

Look in the debug file. When mcsMQTT receives the shutdown request from HS it puts "Shutdown IO" in the log.

mcsMQTT and all local plugins are started and stopped by HS. There really is not too much processing happening in the shutdown sequence that should confuse HS. What did change when I added Express mode and did general optimization is that the database stores generally did not occur during normal operation, but only occurred during shutdown.

[Guest]

after restarting hs3 two times then stopping it.. i now have two process with mcsmqtt .

I will send you the log via pm

[Guest]

Seems like you have exceded you msg quota. I have sent it to your email address. support a mcsSprinklers dot com

[Michael McSharry]

I did not see any shutdownio in the log. This means to me that you are not using a normal shutdown process for HS and just using Linux to kill its process. This means HS has no opportunities to close down its spawned processes in a normal manner. HS under Linux does provide tools/scripts to do a shutdown via browser. Suggest looking at those to see if there is a way to automate it. Aborting rather than normal shutdown could have implications to the integrity on the next startup.

[Guest]

Thanks Michael. If you open it with notepadd++ it is on the line 1829.

Yes i do a proper shudown via a curl

7/5/2019 8:57:39 PM 28878 | HSEvent VALUE_CHANGE| 1024| C484F24D-011-Q53| 0| 8| 161
7/5/2019 8:57:46 PM 36403 | HSEvent VALUE_CHANGE| 1024| ZHAPresence-43| 100| 0| 1108
7/5/2019 8:57:47 PM 36741 | HSEvent STRING_CHANGE| 64| P-2-LastMessage| Hs3Linux is in the shutDown Process to Iphone_matt| 334
7/5/2019 8:57:47 PM 37022 | HSEvent VALUE_CHANGE| 1024| P-4-Remaining| 7309| 7310| 336
7/5/2019 8:57:50 PM 40186 | HSEvent VALUE_CHANGE| 1024| C484F24D-011-Q53| 8| 0| 161
7/5/2019 8:57:50 PM 40246 | HSEvent VALUE_CHANGE| 1024| C484F24D-011-Q53| 0| 8| 161
7/5/2019 8:57:56 PM 45766 | ActoOnMessageForTrigger Topic HS3/MemUSED,Payload=123292 /usr/bin/mono /HomeSeer/HSConsole.exe --log
[B]7/5/2019 8:57:58 PM 47752 | Shutdown IO [/B]
7/5/2019 8:57:58 PM 47757 | MessageSourceExists SELECT count(Source) as extant FROM MQTT_MESSAGE WHERE (Source='Alexa/LastVoiceCommand/salon')=1
7/5/2019 8:57:58 PM 47759 | UpdateRecord UPDATE MQTT_MESSAGE SET Source='Alexa/LastVoiceCommand/salon',Topic='',Payload='what^1s the alarm',Template='',Pattern='',Replace='',Match='0',LastDate= '2019-07-05 20:43:33',Reject=0,Express=0,Accept=1,RetainFlag=0,PluginDev ice=1,Subscribe=0,Chart=0,History=0,Ref=787,ChangeType=1,Mis c=262416,QOS=0,StatusType=3 WHERE (Source='Alexa/LastVoiceCommand/salon'), result=1, Key=Source
7/5/2019 8:57:58 PM 47760 | MessageSourceExists SELECT count(Source) as extant FROM MQTT_MESSAGE WHERE (Source='Alexa/LastVoiceCommand/Basement')=1
7/5/2019 8:57:58 PM 47760 | UpdateRecord UPDATE MQTT_MESSAGE SET Source='Alexa/LastVoiceCommand/Basement',Topic='',Payload='what^1s the alarm',Template='',Pattern='',Replace='',Match='0',LastDate= '2019-07-05 20:43:33',Reject=0,Express=0,Accept=1,RetainFlag=0,PluginDev ice=1,Subscribe=0,Chart=0,History=0,Ref=784,ChangeType=1,Mis c=262416,QOS=0,StatusType=3 WHERE (Source='Alexa/LastVoiceCommand/Basement'), result=1, Key=Source
7/5/2019 8:57:58 PM 47760 | MessageSourceExists SELECT count(Source) as extant FROM MQTT_MESSAGE WHERE (Source='AlexaLastVoiceCommand/LivinRoom/Hour')=1
7/5/2019 8:57:58 PM 47760 | UpdateRecord UPDATE MQTT_MESSAGE SET Source='AlexaLastVoiceCommand/LivinRoom/Hour',Topic='',Payload='0',Template='',Pattern='',Replace='' ,Match='0',LastDate='2019-07-05 20:43:33',Reject=0,Express=1,Accept=1,RetainFlag=0,PluginDev ice=1,Subscribe=0,Chart=0,History=0,Ref=795,ChangeType=1,Mis c=262416,QOS=0,StatusType=2 WHERE (Source='AlexaLastVoiceCommand/LivinRoom/Hour'), result=1, Key=Source
7/5/2019 8:57:58 PM 47761 | MessageSourceExists SELECT count(Source) as extant FROM MQTT_MESSAGE WHERE (Source='AlexaLastVoiceCommand/LivinRoom/Minute')=1
7/5/2019 8:57:58 PM 47761 | UpdateRecord UPDATE MQTT_MESSAGE SET Source='AlexaLastVoiceCommand/LivinRoom/Minute',Topic='',Payload='0',Template='',Pattern='',Replace= '',Match='0',LastDate='2019-07-05 20:43:33',Reject=0,Express=1,Accept=1,RetainFlag=0,PluginDev ice=1,Subscribe=0,Chart=0,History=0,Ref=794,ChangeType=1,Mis c=262416,QOS=0,StatusType=2 WHERE (Source='AlexaLastVoiceCommand/LivinRoom/Minute'), result=1, Key=Source
7/5/2019 8:57:58 PM 47761 | MessageSourceExists SELECT count(Source) as extant FROM MQTT_MESSAGE WHERE (Source='AlexaLastVoiceCommand/LivinRoom/Second')=1
7/5/2019 8:57:58 PM 47762 | UpdateRecord UPDATE MQTT_MESSAGE SET Source='AlexaLastVoiceCommand/LivinRoom/Second',Topic='',Payload='0',Template='',Pattern='',Replace= '',Match='0',LastDate='2019-07-05 20:43:33',Reject=0,Express=1,Accept=1,RetainFlag=0,PluginDev ice=1,Subscribe=0,Chart=0,History=0,Ref=792,ChangeType=1,Mis c=262416,QOS=0,StatusType=2 WHERE (Source='AlexaLastVoiceCommand/LivinRoom/Second'), result=1, Key=Source
7/5/2019 8:57:58 PM 47762 | MessageSourceExists SELECT count(Source) as extant FROM MQTT_MESSAGE WHERE (Source='Alexa/LastVoiceCommand/Bedroom')=1

[Guest]

This is my systmed file :

[Unit]
Description=HomeSeer HS3 Home Automation Server
After=network.target

[Service]
WorkingDirectory=/HomeSeer
ExecStart=/usr/bin/mono /HomeSeer/HSConsole.exe --log
ExecStop=/HomeSeer/stop_homeseer.sh
Restart=always
RestartSec=30
SyslogIdentifier=HomeSeer HS3
StandardOutput=null
KillMode=none
TimeoutStopSec=300

[Install]
WantedBy=multi-user.target

stop_homeseer.sh file

#!/bin/bash
cd /opt/HomeSeer
/usr/bin/curl 'http://127.0.0.1:xxx/JSON?request=runevent&group=Admin&name=Shutdown'
sleep 60s

* maybe I should raise this to more than 60 sec? Will try that


The picture is the event. ( edit: the forum wont allow me to upload tonight?)

and this is the script the event is calling

sub Main(parm as object)
  hs.WriteLog("DoShutdown", "Starting shutdown....")
  hs.Shutdown
End Sub

[zwolfpack]

Here is an ExecStop script that waits until the mono processes terminate before it exits.

#!/bin/sh
# hs3stop.sh - stop the HS3 application
# supports: systemd service shutdown

# import login credentials used to login to web server
# these are ignored if password not required
inifile=$(dirname $0)/Config/$(basename $0 .sh).ini
login=
test -r $inifile && . $inifile

# extract web server port from settings.ini
hs3root=$(dirname $0)  # where this script lives
webport=$(awk -F= '\
{
    gsub("\015", "") # remove CR character
    if ($1 == "gWebSvrPort") print $2
}
' $hs3root/Config/settings.ini)

# send application shutdown command
for i in $(seq 1 5)
do
    curl -f -s -o /dev/null ${login:+-u} $login -X POST -F 'scriptcmd=hs.shutdow
n()' -F 'runscript=Execute Command' "http://localhost:$webport/ControlPanel"
    rc=$?
    test $rc -eq 0 && break
    sleep 2
done

# if curl cmd unsuccessful, terminate main process
test $rc -ne 0 -a -n "$MAINPID" && kill $MAINPID

# delay until all HomeSeer mono processes terminate
mono=$(which mono) || exit
while pgrep -af $mono.'*'\(HSConsole\|HomeSeer\)
do
    sleep 5
done

Included in the download here.

[Guest]

yes i just installed it LOL. like at the same time you posted.


here is the output of ./hs3stop.sh

 ./hs3stop.sh
{ "Response":"ok" }
1396 /usr/bin/mono HSConsole.exe --log
1946 /usr/bin/mono /HomeSeer/HSPI_ZWave.exe
1947 /usr/bin/mono /HomeSeer/HSPI_AKGoogleCalendar.exe
1948 /usr/bin/mono /HomeSeer/HSPI_SKWARE_DEVICE_HISTORY.exe
1950 /usr/bin/mono /HomeSeer/HSPI_PUSHOVER.exe
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1953 /usr/bin/mono /HomeSeer/HSPI_MeiHarmonyHub.exe
1955 /usr/bin/mono /HomeSeer/HSPI_LutronCaseta.exe
1966 /usr/bin/mono /HomeSeer/HSPI_JowiHue.exe
1969 /usr/bin/mono /HomeSeer/HSPI_Jeedom.exe
1981 /usr/bin/mono /HomeSeer/HSPI_SqueezeBox.exe
1989 /usr/bin/mono /HomeSeer/HSPI_ULTRALOG3.exe
1993 /usr/bin/mono /HomeSeer/HSPI_EasyTrigger.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1396 /usr/bin/mono HSConsole.exe --log
1946 /usr/bin/mono /HomeSeer/HSPI_ZWave.exe
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1953 /usr/bin/mono /HomeSeer/HSPI_MeiHarmonyHub.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1396 /usr/bin/mono HSConsole.exe --log
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1953 /usr/bin/mono /HomeSeer/HSPI_MeiHarmonyHub.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1952 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
1997 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
2680 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe

[Michael McSharry]

[quote]Thanks Michael. If you open it with notepadd++ it is on the line 1829.[/qutoe]

I see it now and also see that you have what looks like around 1200 devices and at the time the debug ended about 50% have been recorded to the database. Looks like you need two to three times the timeout that you originally provisioned with the plugin version you are running.

I do see that there is much written to the database during shutdown that does not need to be saved. I can optimize this by saving only those that have changed. It is at http://mcsSprinklers.com/mcsMQTT_4_0_3_1.zip

[Guest]

[QUOTE=Michael McSharry;n1314517]

Thanks Michael. If you open it with notepadd++ it is on the line 1829.[/qutoe]

I see it now and also see that you have what looks like around 1200 devices and at the time the debug ended about 50% have been recorded to the database. Looks like you need two to three times the timeout that you originally provisioned with the plugin version you are running.

I do see that there is much written to the database during shutdown that does not need to be saved. I can optimize this by saving only those that have changed. It is at http://mcsSprinklers.com/mcsMQTT_4_0_3_1.zip

Thanks Michael, I will try this version.
I now have something like 500 Homeseer devices. I have deleted a bunch o device in the past, so this is why i have high reference number in some... but now the count is 500.

[Guest]

Unfortunately I have the same issue . DO you need any new logs ?

[Michael McSharry]

The same log as before to see what is happening after Shutdown IO

[zwolfpack]

From hs3stop.sh transcript, it's going thru the wait loop around 60 times. Loop time is 5 seconds, so approx. 300 seconds total. So likely the TimeoutStopSec=300 in the service file is what finally terminates it.

You could increase that to see if it ever finishes on its own (not sure if that would be of value though).

[Guest]

I think it is resolved now ! we'll get to you tomorow. thanks !

Edit : this was a false positive ( my systemd was not configured properly , so HomeSeer was not properly shudown. This is why it didnt take time to restart the pc.. )...

This is the systemd that i have now that seems to work:

[Unit]
Description=HomeSeer HS3 Home Automation Server
After=network.target

[Service]
WorkingDirectory=/HomeSeer
ExecStart=/usr/bin/mono /HomeSeer/HSConsole.exe --log
ExecStop=/HomeSeer/hs3stop.sh
Restart=always
RestartSec=30
SyslogIdentifier=HomeSeer HS3
StandardOutput=null
KillMode=none
TimeoutStopSec=300

[Install]
WantedBy=multi-user.target

This is the output of ''systemctl status hs3'' I just saw

● hs3.service - HomeSeer HS3 Home Automation Server
   Loaded: loaded (/etc/systemd/system/hs3.service; enabled; vendor preset: enabled)
   Active: active (running) since Sat 2019-07-06 22:39:28 EDT; 7s ago
 Main PID: 20369 ((System)_06-Jul)
    Tasks: 243 (limit: 4915)
   Memory: 466.2M
   CGroup: /system.slice/hs3.service
           ├─ 9122 /bin/sh /HomeSeer/scripts/Hs3Mem.sh
           ├─10595 /bin/sh /HomeSeer/scripts/UPSLaudry.sh
           ├─10595 /bin/sh /HomeSeer/scripts/UPSLaudry.sh
           ├─14999 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe
           ├─18289 /bin/sh /HomeSeer/hs3stop.sh
           ├─19646 sleep 30
           ├─19691 sleep 30
           ├─20369 /usr/bin/mono /HomeSeer/HSConsole.exe --log
           ├─20763 sleep 5
           ├─20771 /usr/bin/mono /HomeSeer/HSPI_EasyTrigger.exe
           ├─20772 /usr/bin/mono /HomeSeer/HSPI_Kodi.exe
           ├─20773 /usr/bin/mono /HomeSeer/HSPI_LutronCaseta.exe
           ├─20774 /usr/bin/mono /HomeSeer/HSPI_ZWave.exe
           ├─20777 /usr/bin/mono /HomeSeer/HSPI_AKGoogleCalendar.exe
           ├─20778 /usr/bin/mono /HomeSeer/HSPI_PUSHOVER.exe
           ├─20780 /usr/bin/mono /HomeSeer/HSPI_MeiHarmonyHub.exe
           ├─20782 /usr/bin/mono /HomeSeer/HSPI_ULTRALOG3.exe
           ├─20785 /usr/bin/mono /HomeSeer/HSPI_BLBackup.exe
           ├─20788 /usr/bin/mono /HomeSeer/HSPI_SKWARE_DEVICE_HISTORY.exe
           ├─20791 /usr/bin/mono /HomeSeer/HSPI_Jeedom.exe
           ├─20794 /usr/bin/mono /HomeSeer/HSPI_JowiHue.exe
           ├─20797 /usr/bin/mono /HomeSeer/HSPI_SqueezeBox.exe
           └─20801 /usr/bin/mono /HomeSeer/HSPI_MCSMQTT.exe

Jul 06 22:39:28 automation systemd[1]: This usually indicates unclean termination of a previous run, or service imple
Jul 06 22:39:28 automation systemd[1]: hs3.service: Found left-over process 18289 (hs3stop.sh) in control group while
Jul 06 22:39:28 automation systemd[1]: This usually indicates unclean termination of a previous run, or service imple
Jul 06 22:39:28 automation systemd[1]: hs3.service: Found left-over process 19646 (sleep) in control group while star
Jul 06 22:39:28 automation systemd[1]: This usually indicates unclean termination of a previous run, or service imple
Jul 06 22:39:28 automation systemd[1]: hs3.service: Found left-over process 19691 (sleep) in control group while star
Jul 06 22:39:28 automation systemd[1]: This usually indicates unclean termination of a previous run, or service imple
Jul 06 22:39:28 automation systemd[1]: hs3.service: Found left-over process 20366 (sleep) in control group while star
Jul 06 22:39:28 automation systemd[1]: This usually indicates unclean termination of a previous run, or service imple
Jul 06 22:39:28 automation systemd[1]: Started HomeSeer HS3 Home Automation Server.

----



Mcsmqtt PI do not shutdown when hs is shutdown properly. I send you the log in an instant Michael McSharry. I had to wait the full 300 secs for hs3 to restart when entered the command '' systemctl stop hs3''