Help on how to troubleshoot a plugin....

I have a plugin that used to work fine that someone abandoned (https://github.com/garrettwp/mios-universal-devices-isy-plugin)

The plugin connects to an ISY994i controller and enumerates the devices on that controller (this works on both vera and openLuup)

It then has a daemon that runs and listen for events coming from the ISY (i think it binds to the ISY for state changes but i am not sure and it may be the thing that sends data to thge ISY). On a real vera the ‘running’ status shows as running, in the device UI. But shows as disconnected (it needs to show connected to receive events) - it sends events to the ISY just fine (like set brightness level)

In openLuup it never shows as running.

In the openLuup i see the following over and over again.
2016-03-08 20:40:30.195 luup_log:4: ISYController: debug: Daemon is not running. Starting daemon.
2016-03-08 20:40:30.196 luup_log:4: ISYController: debug: Starting ISY Event Daemon.

This is accompanied by my root console on pi echoing:
/bin/sh: 0: Can’t open /etc/rc.common (edit: oh i see how that makes sense now seeing the script below! i created an empty rc.common and that got rid of the console error but not much else :slight_smile:

I am running init in the context of root

I noticed looking in the L_ISYController1.lua that it as a pid file and initscript path (bear with me i am noob on linux)

local pidFile = "/var/run/isy_event_daemon.pid" local initScriptPath = "/etc/init.d/isy_event_daemon"

when i looked at the isy_event_daemon file (i have no idea how this got created - i can only assume one of the LUA files for the device created this?) i see a complex script (i assume this is what is run when i click initialize in the device in altui)

I think that pluto.lzo is being called in the script to decompress the lzo’d lua file (this would be a problem as a)the file is not compressed because of getfiles and b)pluto-lzo is not a command on the pi on wheezy :slight_smile:

[code]#!/bin/sh /etc/rc.common

Copyright (C) 2007 OpenWrt.org

START=80
PID_FILE=/var/run/isy_event_daemon.pid
PROXY_DAEMON=/tmp/isy_event_daemon.lua

start() {
if [ -f “$PID_FILE” ]; then
# May already be running.
PID=$(cat “$PID_FILE”)

    if [ -d "/proc/$PID" ]; then
        COMMAND=$(readlink "/proc/$PID/exe")

        if [ "$COMMAND" = "/usr/bin/lua" ]; then
            echo "Daemon is already running"
            return 1
        fi
    fi
fi

# Find and decompress the proxy daemon Lua source.
if [ -f /etc/cmh-ludl/L_ISYEventDaemon.lua.lzo ]; then
    PROXY_DAEMON_LZO=/etc/cmh-ludl/L_ISYEventDaemon.lua.lzo
    
elif [ -f /etc/cmh-lu/L_ISYEventDaemon.lua.lzo ]; then
    PROXY_DAEMON_LZO=/etc/cmh-lu/L_ISYEventDaemon.lua.lzo
fi

if [ -n "$PROXY_DAEMON_LZO" ]; then
    /usr/bin/pluto-lzo d "$PROXY_DAEMON_LZO" "$PROXY_DAEMON"
fi

# Close file descriptors.
for fd in /proc/self/fd/*; do
    fd=${fd##*/}
    case $fd in
        0|1|2) ;;
        *) eval "exec $fd<&-"
    esac
done

# Run daemon.
/usr/bin/lua "$PROXY_DAEMON" </dev/null >/dev/null 2>&1 &
echo "$!" > "$PID_FILE"

}

stop() {
if [ -f “$PID_FILE” ]; then
PID=$(cat “$PID_FILE”)

    if [ -d "/proc/$PID" ]; then
        COMMAND=$(readlink "/proc/$PID/exe")

        if [ "$COMMAND" = "/usr/bin/lua" ]; then
            /bin/kill -KILL "$PID" && /bin/rm "$PID_FILE"
            return 0
        fi
    fi
fi
echo "Daemon is not running"
return 1

}[/code]

–edit–
OIC the L_ISYEvent.Lua makes the script when the initialize action button in the UI is pressed.
So I guess i would need to modify the elseifs to have a condition on what to do if the file is already decompressed! oh my i amgoing to have to clone this in git :frowning:

i am on the right direction?

interestingly i modified the L_ISYEvent.Lua and deleted the file in /etc/init.d and called the initialize action from the ALTUI device node.

It didn’t recreate the script. I put the old L_ISYEvent.Lua back and tried again. It didn’t recreate the init.d script. So i manually created the script an ensured it was 755, however when it was called the console echoed a permissions issue. Very strange.

I see this plugin might log to luup.log - i cant find this?

Lastly when i was using this plugin in anger when UI7 first happened i saw all sorts of issues when recreating the device, like not being able to set the variables (i enter them in the fields but they have disappeared when i go back in. I am seeing same issue in openLuup. So i guess whatever issue is it is common across the vera and openLuup?

It looks as though this plugin delves deep into the depths of Vera, and you have already found some missing items, like directories.

For the pluto-lzo problem, there are two basic approaches:

[ol][li]modify the source code (which I don’t like doing)[/li]
[li]create a dummy pluto-lzo which does nothing but copy the file and change its extension. [/li][/ol]

Plugins which modify compressed files make assumptions about their environment which are not necessarily true for openLuup. This is understandable, but regrettable. I may include solution #2 as part of the standard distribution in future, but it may not be a total solution.

To get your particular plugin running it may be most expedient to go route #1, however distasteful that is, for the moment.

I’ll take a look myself at the Lua file you posted.


Edit: this would never have run unmodified under Windows since it spawns UNIX command scripts.

Also, luup.log() writes to LuaUPnP.log, which you will find in /etc/cmh-ludl/ along with the last 5 versions.

[quote=“akbooer, post:3, topic:191498”]It looks as though this plugin delves deep into the depths of Vera, and you have already found some missing items, like directories.

For the pluto-lzo problem, there are two basic approaches:

[ol][li]modify the source code (which I don’t like doing)[/li]
[li]create a dummy pluto-lzo which does nothing but copy the file and change its extension. [/li][/ol]

Plugins which modify compressed files make assumptions about their environment which are not necessarily true for openLuup. This is understandable, but regrettable. I may include solution #2 as part of the standard distribution in future, but it may not be a total solution.

To get your particular plugin running it may be most expedient to go route #1, however distasteful that is, for the moment.

I’ll take a look myself at the Lua file you posted.


Edit: this would never have run unmodified under Windows since it spawns UNIX command scripts.

Also, luup.log() writes to LuaUPnP.log, which you will find in /etc/cmh-ludl/ along with the last 5 versions.[/quote]

Thanks, yes i am starting to realize how deep the rabbit hole goes!

At this point i have modified the init.d script to call the uncompressed LUA file (i replaced the variable in the command with a fixed string). Ultimately i am thinking i will put something into the script to effectively change the behaviour if running on openLuup (i have a clone of the plugin source in github and as it is abandoned have no qualms about creating a fork), i worked out which lus script creates the init.d script file and think i may modify it as follows:

if [ -f /etc/cmh-ludl/L_ISYEventDaemon.lua ]; then PROXY_DAEMON=/etc/cmh-ludl/L_ISYEventDaemon.lua fi

I would put that just before the command to execute $PROXY_DAEMON

However the bigger issue is this script is never getting called properly by the function in L_ISYController1.lua ‘function running()’ that calls the script file using ‘os.execute(initScriptPath … " start")’ where initScriptPath = “/etc/init.d/isy_event_daemon” - i think the “start” means it is trying to call the script as a service, and the script i think assumes there is a full rc.common with all the commands defined (i went and looked at the rc.common on the actual vera, woah that looks nothing like my rc.local on the pi!).

I am assuming i can’t just copy the rc.common from the vera to the pi and that it is way more complex than that. right?

–edit-- thanks for the confirmation on the log - i saw that in the code, this means i can copy that as an example to start writing more things out to logs so i can trace better (honest i am not a programmer, would have no clue how to construct any of this from scratch!)

as a note I think this is what is happening in the main LUA script.

It looks to see if the daemon is running by a PID file in /var/run if it find that then the other functions in the plugin are called.
The PID file is created by the init.d script that is called using the start function / integration with rc.common.

While I am guessing the quick fix would be to create a small version of the init.d script which just calls the daemo lua script and makes a PID file? My only concern is the original author seems to use the stop and restart functions of rc.common too :frowning:

Also, not sure if you remember but i said this is not working on the vera (the difference is on the vera the init.d script runs fine as rc.common and stuff need for that is aok). Using the pi inspired me to be brave and root into the vera and find the luup.log.

I now know where it is failing on a real vera and it is in this function in the L_ISYController1.lua, in the luup.log i see “Initializing and subscribing to ISY.” but no more so i assume it is failing in this function. Is that good assumption? Could you point me at somethings to look at?

[code]function daemonConnect()
debugLog(“Initializing and subscribing to ISY.”)

if (running()) then
if (isyIP ~= nil and isyUser ~= nil and isyPass ~= nil) then
local body = “” … PARENT … “” …
isyIP … “” … isyPort … “” …
isyUser … “” … isyPass … “”

        local t = {}
        local request, code, headers = http.request {
            url = "http://127.0.0.1:9810",
            method = "PUT HTTP/1.1",
            sink = ltn12.sink.table(t),
            source = ltn12.source.string(body),
            headers = {
                ["Content-Length"] = tostring(body:len()),
                ["Content-Type"] = "text/xml; charset=utf-8"
            }
        }
        
        if (code == 200) then
            debugLog("Successfully sent configuration data to ISY Event Daemon.")

            local t = {}
            local request, code, headers = http.request {
                url = "http://127.0.0.1:9810",
                method = "SUBSCRIBE HTTP/1.1",
                sink = ltn12.sink.table(t)
            }
            
            if (code == 200) then
                debugLog("Successfully issued subscribe to ISY Event Daemon.")

            end
        end
    end
end

end[/code]

ahh i think this is a function to test a process already bound to port 9810 - i think that is actually handled in the L_ISYEVENTDaemon.lua here, so i guess i need to figure out if the process is correctly bound to port 9810 and it is this function that should be creating the process bound to the vera:9810?

[code]local function subscribe(c)

if (ISY_IPADDRESS ~= nil and ISY_PORT ~= nil and ISY_USERNAME ~= nil and ISY_PASSWORD ~= nil) then
    -- get vera ip address
    local veraIP = getIPAddress(ISY_IPADDRESS)
    
    if (veraIP) then
        body = "<s:Envelope><s:Body><u:Subscribe" ..
        " xmlns:u=\'urn:udi-com:service:X_Insteon_Lighting_Service:1\'>" ..
        "<reportURL>http://" .. veraIP .. ":" .. LISTEN_PORT .. "/</reportURL>" ..
        "<duration>infinite</duration>" ..
        "</u:Subscribe></s:Body></s:Envelope>\r\n"

        local t = {}
        request, code, headers = http.request {
            url = "http://" .. ISY_IPADDRESS .. ":" .. ISY_PORT,
            method = "POST /services HTTP/1.1",
            sink = ltn12.sink.table(t),
            source = ltn12.source.string(body),
            headers = {
                ["Content-Length"] = tostring(body:len()),
                ["Content-Type"] = "text/xml; charset=utf-8",
                ["Authorization"] = "Basic " .. (mime.b64(ISY_USERNAME .. ":" .. ISY_PASSWORD)),
                ["SOAPACTION"] = "urn:udi-com:service:X_Insteon_Lighting_Service:1#Subscribe",
                ["Connection"] = "Keep-Alive"
            }
        }
        
        httpResponse = table.concat(t)
        
        if (DEBUG == true) then
            --print(httpResponse)
            --print(code)
        end
        
        -- Check the http response code
        if (code == 200) then
            if (DEBUG == true) then
                log("Successfully subscribed to ISY.")
            end
            
            c:send("HTTP/1.1 200 Successfully subscribed to ISY.\r\n\r\n")
            
        else
            if (DEBUG == true) then
                log("Could not subscribe to ISY.")
            end
            
            c:send("HTTP/1.1 500 Could not subscribe to ISY.\r\n\r\n")
        end
        
    else
        if (DEBUG == true) then
            log("Could not get Vera's ip address.")
        end
        
        c:send("HTTP/1.1 500 Could not get Vera's ip address.\r\n\r\n")
    end

else
    if (DEBUG == true) then
        log("Could not subscribe to ISY.")
    end
    
    c:send("HTTP/1.1 500 Could not subscribe to ISY.\r\n\r\n")

end

return true

end [/code]

OK I give UP.

I went through L_ISYEventDaemon.lua and changed a bunch of log(xyz) calls to debugLog(xyz) calls to try and start tracing, i uploaded this modified file to the vera (i had already turned debug=true on the ISY device)

I went to ALTUI and it had the no handler error.
I went to VeraUI and rebooted the box.

When it all came up the plugin was working fine!? Hasn’t worked in weeks and through 2 firmware updated (and possibly months and a bunch of missed firmware updates).

I have no clue :slight_smile: other to say woah this is all so fragile.

I would still like to find a way to get this plugin working on the openLuup pi i have… and see if that makes it more stable…

I hope you’re talking about the plugin, here, and not openLuup?

I hope you’re talking about the plugin, here, and not openLuup?[/quote]
heheh yeah - the plugin must be real crappy, the issues i saw on a vera 18mo ago when UI7 released i am still seeing on vera now and openLuup (for example the plugin not letting me set variables and needing to hard reboot the vera / restet openLuup and start again) i assume this is some fundamental flaw in Lua / how services are constructed in the vera model.

Quick question, the shell script i can;t start because of no rc.common on pi. I assume i have two options:

  1. hard code in the LUA script the starting of the shell scrip and then hardcode in the shell scrip the LUA file it calls
  2. re-write the init.d shell script code to support start / stop etc - i think i found a template to use as an example Raspberry PI dscServer auto-start - DSCLink - Universal Devices Forum

make sense as a direction?

(and do you think i should target raspbian wheezy and do it with init.d or jessie and do with systemd)

Looking at the daemon, I see that it is just an HTTP server which responds to POST requests and does the right action call to Vera. Why it’s written like this (apart from the fact that it’s borrowed from bits of existing code elsewhere) I have no real clue, although I’m sure it seemed like a good idea at the time. There’s no real need to spawn a separate daemon - I believe this could be integrated into one piece of device code. However, not having the actual device, or the need, I’m not offering to do it!

Actually, I don’t have the expertise to advise on the specific questions you asked, either. Sorry.

Certainly wasn’t expecting you to re-write any of it :slight_smile:

Also given bizarrely it is now started working on the Vera (after months of not working) my motivation has dropped. I will come back to it next time it has an extended freakout!

If I happen to upgrade my pi’s to jessie i think I will go the systemd route. If i do that i will clone the github for the plugin and make a pure pi/openLuup variant.

I also meant to say, thanks for holding my hand and helping me understand how the LUA files are processed and work.