Custom App not running on the latest firmware 5.1.2.

[Ajay K]

We have been using a customapp in the previous version of the conduit and firmware version 1.7.4 without issues, since then we upgraded to the new gateway and here is what I have from the home page on the gateway for the model and version of firmware.

mPower™ Edge Intelligence Conduit – Application Enablement Platform
MTCDT-L4N1-246A Firmware 5.1.2

The customapp was installed successfully and here is the start script. I am guessing the customapp fails to run, because the custom app accesses the file system and doesn’t have permissions, given everything has to run under the root account in the new firmware of the conduit. However I am not sure why as a custom app developer I need to ensure that it runs under the root account, why can’t the app manager which ends up running this custom app ensure that it runs under the root account or do I have to do anything during the install process so the customapp runs under the root account?

#!/bin/bash

# This Start script is used by the app-manager program to start and stop
# applications. app-manager invokes this script with the 'start' option on boot
# and when the app-manager start command is run. app-manager invokes this
# script with the 'stop' option on shutdown and when the app-manager stop
# command is run.
#
# app-manager requires this script to accept the following command line
# arguments:
#
#   start - start the application process(es)
#   stop  - stop the application process(es)
#   restart - restart the application process(es)
#   reload - reload the application configuration (new config downloaded)
#
#
# This script is a fully cusomizable template that can be used to initialize
# the environment for executing the application and starting all processes.
# This script is the supported framework to start and stop an application.

NAME="TestCustomApp"
APP_LOGDIR="/var/log"

# Use MultiTech Provided $APP_DIR environment variable
DAEMON="/usr/bin/node"
DAEMON_ARGS="$APP_DIR/app.js > $APP_LOGDIR/$NAME.log 2>&1"
#DAEMON_ARGS="$APP_DIR/app.js"

RUN_DIR=$APP_DIR

START_STOP_DAEMON="/usr/sbin/start-stop-daemon"
PID_FILE="/var/run/$NAME.pid"

# Set custom environment variables for the application execution
function SetEnv {
# MultiTech Provided Environment Variables:
#    CONFIG_DIR
#    APP_DIR
#    APP_ID

    echo "SetEnv"

    echo $CONFIG_DIR
    logger -t Start "$CONFIG_DIR"
    echo $APP_DIR
    logger -t Start "$APP_DIR"
    echo $APP_ID
    logger -t Start "$APP_ID"
}

# This function can be used to chmod files and implement any security initialization
function CreateAccess {
    echo "CreateAccess:"
}

# Intended to be a hook allowing the application to be executed as a non-root user.
function ChangeUser {
    echo "ChangeUser:"
}

# The nuts and bolts of starting the application process.
function ExecuteStart {
    echo "ExecuteStart:"
    echo $RUN_DIR
    
    logger -t Start "exec $DAEMON $DAEMON_ARGS"

    # This demonstrates how to optionally use start-stop-daemon
    # http://man.he.net/man8/start-stop-daemon
    $START_STOP_DAEMON --start --background --pidfile "$PID_FILE" --make-pidfile --chdir "$RUN_DIR" --startas /sbin/customapp-angel -- /bin/bash -c "exec $DAEMON --max-old-space-size=40 -- $DAEMON_ARGS"
    logger -t Start "Exec $DAEMON $DAEMON_ARGS completed!"
}

# Start the application running process(es)
function Start {
    SetEnv
    CreateAccess
    ChangeUser
    ExecuteStart
}

# Stop the application running process(es)
function Stop {
    echo "Stop:"

    # This demonstrates how to optionally use start-stop-daemon
    $START_STOP_DAEMON --stop -p "$PID_FILE" --retry 60
}

# Effectively stop and start the application again.
function Restart {
    echo "Restart:"
    Stop
    sleep 1
    Start
}

# Notify the application process that new config files are available
function Reload {
    echo "Reload:"
    # Restart
    # Could SIGHUP your process if it supports it instead of restarting
}

#Gather options from command line
# Reset in case getopts has been used previously in the shell.
OPTIND=1

case "$1" in
    # start is invoked by app-manager after install, on boot, and
    # during config install
    start)
        echo -n "Starting $NAME: "
        Start
        ;;
    # stop is invoked by app-manager before shutdown, and during config install
    stop)
        echo -n "Stopping $NAME: "
        Stop
        ;;
    # restart is invoked by app-manager when the app is explicitly restarted
    restart)
        echo -n "Restarting $NAME: "
        Restart
        ;;
    # reload is invoked by app-manager after a new config has been installed
    reload)
        echo -n "Restarting $NAME: "
        Reload
        ;;
    *)
        echo "Usage: $0 {start|stop|restart|reload}" >&2
        exit 1
        ;;
esac

exit 0

Thanks,
Ajay

[Jeff Hatch]

Hello William,

The app-manager executes the start script with root privilege and is effectively root. What are the permissions on the files that are not accessible and where are they on the system?

Thank You,

Jeff

[Ajay K]

Hi Jeff,

Not sure why you addressed me as William :). Anyway if the app-manager is executing the start script under the root privilege, not sure why the app is not running? There is no application logs for the application being created, the status.json is not getting updated with the current status of the application. This is why I was assuming the issues were related to the application accessing the specific files in the file system.

The application related log file is being created under /var/logs and the status.json file is right under the application install directory and the <application>.pid file /var/run/ folder. None of these files are either being updated or logs being generated. If look at the messages log file under the /var/logs folder all I see an entry that indicates the application was started successfully, but nothing beyond that. Is there a better way to troubleshoot what is happening once the app-manager starts the application?

If I just run the application from the command prompt using the sudo command the application runs fine without any issues. i.e. for ex:

sudo /usr/bin/node /var/config/apps/TestCustomApp/app.js

Thanks,
Ajay.

[Jeff Hatch]

Hello Ajay,

I mean …,:) Sorry about the name deal. Lot’s going on and I have problems remembering who I’m talking with somtimes:(

Anyway, It is possible to run the app-manager “by hand” at the command line and execute the custom application. Running “app-manager -h” prints out the options. You would execute something like this:

app-manager –command start –appid –appname

You can get the app_id and app_name from the app-manager database. A lot of the time “app-manager –command status” will print out the application information, but I’m not sure that the app_id would be available. Doing a “cat /var/config/AppManager.json” will print all the info that app-manager has on any apps installed.

If running app-manager by hand at the command line doesn’t yield any more information or errors, then you might have to run the start script by hand and even the app itself.

Jeff

[Ajay K]

Hi Jeff,

Here is what I get when I run the app-manager from the command prompt.

admin@mtcdt:~$ sudo app-manager –command start –appid “LOCAL”
AppCommand::executeStartScript: executing: /var/config/app/OrcellApp/Start start
Success!

This is what is reported in the messages log file.

2020-03-23T17:38:50.141277+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: Getting app statuses
2020-03-23T17:38:50.215028+00:00 mtcdt APPMANAGER: AppCommand::getBasePathFor: unknown app type. Defaulting to custom
2020-03-23T17:38:50.219330+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: can’t read pid as a string, trying as number:#012

So bottom line there are not more details as to why the custom app is not getting launched.

Also I was looking the /var/config/db.json shouldn’t there be an entry for customapps in it? currently the customapp section in the file is as shown below.

“customApps” : {},

One other thing I noticed even node red logs used to be created in the previous version of the firmware, I don’t see node red logs being created either.

At this point we are completely blocked, I am not sure what this successfully runs in prior version of the conduit firmware, specifically 1.7.4 and not in this version of the conduit firmware 1.5.2.

Thanks,
Ajay

[Jeff Hatch]

Hello Ajay,

After you have installed the custom application, have you logged into the Web UI and looked to see if the application can be found on the Apps page? The customApps data doesn’t persist if I recall correctly. It is an in-memory thing in the API at run-time. What is the output of the “app-manager –command status”?

Are you able to execute the application by hand directly in /var/config/app/Orcellap? Also, are you running this application on an MTR or Conduit? I see the “rcell” in the app name and am just wondering.

Thank You,

Jeff

[Ajay K]

Hi Jeff,

Thanks for your quick response and yes I see it in the web ui indicating it was successfully installed and I have the ability to start and stop the custom app from the web ui.

As far as the command o/p for “app-manager –command status” here is the o/p

admin@mtcdt:~$ sudo app-manager –command status
{
“Apps” :
[
{
“AppDescription” : “Orcell Application”,
“AppId” : “LOCAL”,
“AppInfo” : “”,
“AppName” : “OrcellApp”,
“AppType” : “CUSTOM”,
“AppVersion” : “4.0”,
“AppVersionNotes” : “App Version with the latest Gateway hardware”,
“Enabled” : true,
“status” : “STOPPED”
}
]
}

Orcell is just a name for our app and we use the conduit and the version of the conduit is at the beginning of this thread. Also like I mentioned earlier in the thread, if i just run the /var/bin/node and my applications app.js it runs fine without any issues.

Also based on increasing the log level, it clear that the start command is being called correctly. The command it would have called eventually to run our custom app would have been this.

/usr/sbin/start-stop-daemon –start –background –pidfile “/var/run/OrcellApp.pid” –make-pidfile –chdir “/var/config/app/OrcellApp” –startas /sbin/orsat-angel — /bin/bash -c “exec /usr/bin/node –max-old-space-size=40 — /var/config/app/OrcellApp/app.js > /var/log/OrcellApp.log 2>&1

However I see in the log entries that the above command is being called, but nothing seems to happen. Log files have the following entries now…let me know if there is anything else I can do to troubleshoot this further.

2020-03-23T19:42:57.755805+00:00 mtcdt Start: /var/config/app/OrcellApp
2020-03-23T19:42:57.838459+00:00 mtcdt Start: LOCAL
2020-03-23T19:42:57.938624+00:00 mtcdt Start: exec /usr/bin/node /var/config/app/OrcellApp/app.js > /var/log/OrcellApp.log 2>&1
2020-03-23T19:42:58.284646+00:00 mtcdt Start: Exec /usr/bin/node /var/config/app/OrcellApp/app.js > /var/log/OrcellApp.log 2>&1 completed!
2020-03-23T19:42:58.325324+00:00 mtcdt APPMANAGER: AppDataDB::SetAppData: updating app info in /var/config/AppManager.json with appId: LOCAL
2020-03-23T19:42:58.396101+00:00 mtcdt APPMANAGER: Released lock on fd
2020-03-23T19:42:58.397423+00:00 mtcdt APPMANAGER: Exiting with success status
2020-03-23T19:42:58.501236+00:00 mtcdt APPMANAGER: LockFile::GetLockNB: attempting to get file lock
2020-03-23T19:42:58.502640+00:00 mtcdt APPMANAGER: LockFile::GetLockNB: Got lock on fd 6
2020-03-23T19:42:58.505451+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: Getting app statuses
2020-03-23T19:42:58.510282+00:00 mtcdt APPMANAGER: AppCommand::getBasePathFor: unknown app type. Defaulting to custom
2020-03-23T19:42:58.537456+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: can’t read pid as a string, trying as number:#012 in Json::Value::asCString(): requires stringValue
2020-03-23T19:42:58.554107+00:00 mtcdt APPMANAGER: Released lock on fd
2020-03-23T19:42:58.555288+00:00 mtcdt APPMANAGER: Exiting with success status

Thanks,
Ajay

[Ajay K]

I will open a ticket as this is blocking us.

Thanks,
Ajay

[Jeff Hatch]

Hello Ajay,

Sorry about the delay. I’m pretty bogged down with a bunch of things and am having a hard time getting back to this. I agree that the best route right now is to file a support portal case. It will at least get another set of eyes on it.

Jeff

[Ajay K]

Thanks Jeff for always taking the time to jump in and help. I have opened a ticket and hopefully we can resolve this issue ASAP.

Thanks,
Ajay

[Tom Z]

hi,
did you find a solution for this?

our script will randomly stop

and the last message I see is:

2021-05-03T14:41:02.572515+00:00 mtcdt ppp-rx-monitor: No packets Received from last 2130 seconds
2021-05-03T14:41:32.843217+00:00 mtcdt ppp-rx-monitor: No packets Received from last 2160 seconds
2021-05-03T14:42:03.038134+00:00 mtcdt ppp-rx-monitor: No packets Received from last 2190 seconds
2021-05-03T14:42:20.241522+00:00 mtcdt APPMANAGER: LockFile::GetLockNB: attempting to get file lock
2021-05-03T14:42:20.242940+00:00 mtcdt APPMANAGER: LockFile::GetLockNB: Got lock on fd 5
2021-05-03T14:42:20.623567+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: Getting app statuses
2021-05-03T14:42:20.629987+00:00 mtcdt APPMANAGER: AppCommand::getBasePathFor returning /var/config/app/
2021-05-03T14:42:20.633370+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: can't read pid as a string, trying as number:#012 in Json::Value::asCString(): requires stringValue
2021-05-03T14:42:20.635486+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: kill 0 detected process at 2815, setting status to RUNNING
2021-05-03T14:42:20.643069+00:00 mtcdt APPMANAGER: Released lock on fd
2021-05-03T14:42:20.643731+00:00 mtcdt APPMANAGER: Exiting with success status
2021-05-03T14:42:33.121958+00:00 mtcdt ppp-rx-monitor: No packets Received from last 2220 seconds
2021-05-03T14:42:50.453283+00:00 mtcdt APPMANAGER: LockFile::GetLockNB: attempting to get file lock
2021-05-03T14:42:50.454696+00:00 mtcdt APPMANAGER: LockFile::GetLockNB: Got lock on fd 6
2021-05-03T14:42:50.877799+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: Getting app statuses
2021-05-03T14:42:50.883935+00:00 mtcdt APPMANAGER: AppCommand::getBasePathFor returning /var/config/app/
2021-05-03T14:42:50.888186+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: can't read pid as a string, trying as number:#012 in Json::Value::asCString(): requires stringValue
2021-05-03T14:42:50.889581+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: kill 0 detected process at 2815, setting status to RUNNING
2021-05-03T14:42:50.897556+00:00 mtcdt APPMANAGER: Released lock on fd
2021-05-03T14:42:50.898960+00:00 mtcdt APPMANAGER: Exiting with success status

what strange is that in some cases, I see this same error, but the script doesn’t malfunctions

and in other cases I see the same error and I see a script restart in the logs

2021-05-03T12:46:23.243569+00:00 mtcdt annexcd: [INFO] mts_device_interface.cc:getNetworkInterface:444: link_type = ETHER
2021-05-03T12:46:23.271378+00:00 mtcdt annexcd: [DEBUG] courier.cc:InspectContainer:149: send container: packages {#012  message_id: 172#012  time_packaged: "2021-05-03T12:46:22Z"#012  time_sent: "2021-05-03T12:46:23Z"#012  content {#012    type: TYPE_ATTRIBUTE#012    attribute {#012      type: TYPE_NETWORK_INTERFACE#012      network_interface {#012        name: "br0"#012        link_type: LINK_TYPE_ETHER#012        flags {#012          up: true#012          lower_up: true#012          loopback: false#012          broadcast: true#012          pointtopoint: false#012          multicast: true#012          dynamic: false#012          noarp: false#012          allmulti: false#012          promisc: false#012        }#012        mtu: 1500#012        inet_settings {#012          method: METHOD_MANUAL#012          ip_addrs {#012            addr: 16951488#012            network_prefix_length: 24#012          }#012          default_route: 16951488#012          name_servers: 4261521600#012          interface_name_servers {#012            name_servers: 0#012          }#012        }#012        link_statistics {#012          rx_bytes: 0#012          rx_packets: 0#012          rx_errors: 0#012          rx_dropped: 0#012          rx_overrun: 0#012          rx_multicast: 0#012          tx_bytes: 42#012          tx_packets: 1#012          tx_errors: 0#012          tx_dropped: 0#012          tx_carrier: 0#012          tx_collisions: 0#012        }#012        current_wan: false#012      }#012    }#012  }#012}#012
2021-05-03T12:46:23.299298+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillDhcpServer:562: filling dhcp service message
2021-05-03T12:46:23.301487+00:00 mtcdt annexcd: [INFO] delivery_agent.cc:RunnableCore:3590: sending GPS data
2021-05-03T12:46:23.302232+00:00 mtcdt annexcd: [INFO] delivery_agent.cc:RunnableCore:3593: gpgaa: 
2021-05-03T12:46:23.303524+00:00 mtcdt annexcd: [INFO] delivery_agent.cc:RunnableCore:3594: gpgll: 
2021-05-03T12:46:23.304341+00:00 mtcdt annexcd: [INFO] delivery_agent.cc:RunnableCore:3606: sending active apps
2021-05-03T12:46:23.306308+00:00 mtcdt annexcd: [INFO] mts_device_interface.cc:getActiveApps:527: Skip node-red apps as node-red is not supported
2021-05-03T12:46:23.346141+00:00 mtcdt annexcd: [DEBUG] courier.cc:InspectContainer:149: send container: packages {#012  message_id: 173#012  time_packaged: "2021-05-03T12:46:23Z"#012  time_sent: "2021-05-03T12:46:23Z"#012  content {#012    type: TYPE_ATTRIBUTE#012    attribute {#012      type: TYPE_DHCP_SERVER#012      dhcp_server {#012        enabled: true#012        range_start: 1677895872#012        range_end: 4261587136#012        lease_time: 86400#012        netmask: 16777215#012        gateway: 16951488#012        dns: 16951488#012        interface: "br0"#012        leases {#012        }#012        fixed_addresses {#012        }#012      }#012    }#012  }#012}#012packages {#012  message_id: 174#012  time_packaged: "2021-05-03T12:46:23Z"#012  time_sent: "2021-05-03T12:46:23Z"#012  content {#012    type: TYPE_ATTRIBUTE#012    attribute {#012      type: TYPE_GPS_NMEA#012      gps_nmea {#012        gpgga: ""#012      }#012    }#012  }#012}#012
2021-05-03T12:46:23.455495+00:00 mtcdt APPMANAGER: LockFile::GetLockNB: attempting to get file lock
2021-05-03T12:46:23.456924+00:00 mtcdt APPMANAGER: LockFile::GetLockNB: Got lock on fd 5
2021-05-03T12:46:23.705925+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: Getting app statuses
2021-05-03T12:46:23.712323+00:00 mtcdt APPMANAGER: AppCommand::getBasePathFor returning /var/config/app/
2021-05-03T12:46:23.717049+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: can't read pid as a string, trying as number:#012 in Json::Value::asCString(): requires stringValue
2021-05-03T12:46:23.718691+00:00 mtcdt APPMANAGER: AppCommand::executeStatus: kill 0 detected process at 2815, setting status to RUNNING
2021-05-03T12:46:23.726695+00:00 mtcdt APPMANAGER: Released lock on fd
2021-05-03T12:46:23.727851+00:00 mtcdt APPMANAGER: Exiting with success status
2021-05-03T12:46:23.739908+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillActiveApps:1091: =======================================
2021-05-03T12:46:23.741101+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillActiveApps:1092: App type = CUSTOM
2021-05-03T12:46:23.743669+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillActiveApps:1093: App name = IotGatewayRecieverMQTT
2021-05-03T12:46:23.745468+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillActiveApps:1094: App _id = 60009a81d76dad6793d4e7c6
2021-05-03T12:46:23.746660+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillActiveApps:1095: App version = 2.5
2021-05-03T12:46:23.748280+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillActiveApps:1096: App status = RUNNING
2021-05-03T12:46:23.749459+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillActiveApps:1097: App info = Published success for proxy.iot-experts.net on topic /incoming/thingsboard#012
2021-05-03T12:46:23.750682+00:00 mtcdt annexcd: [DEBUG] delivery_agent.cc:FillActiveApps:1107: Adding this app to ActiveApps annex message..
2021-05-03T12:46:23.751993+00:00 mtcdt annexcd: [INFO] delivery_agent.cc:SendActiveApps:1022: Sending Active Apps data
2021-05-03T12:46:23.754048+00:00 mtcdt annexcd: [INFO] delivery_agent.cc:RunnableCore:3616: sending lora
2021-05-03T12:46:23.771958+00:00 mtcdt annexcd: [DEBUG] courier.cc:InspectContainer:149: send container: packages {#012  message_id: 175#012  time_packaged: "2021-05-03T12:46:23Z"#012  time_sent: "2021-05-03T12:46:23Z"#012  content {#012    type: TYPE_ATTRIBUTE#012    attribute {#012      type: TYPE_ACTIVE_APPS#012      active_apps {#012        active_apps {#012          name: "IotGatewayRecieverMQTT"#012          id: "60009a81d76dad6793d4e7c6"#012          version: "2.5"#012          status: "RUNNING"#012          info: "Published success for proxy.iot-experts.net on topic /incoming/thingsboard\n"#012          type: "CUSTOM"#012        }#012      }#012    }#012  }#012}#012
2021-05-03T12:46:23.951725+00:00 mtcdt annexcd: [INFO] delivery_agent.cc:FillLoraServerStats:1129: lora network is running
2021-05-03T12:46:23.951984+00:00 mtcdt annexcd: [INFO] delivery_agent.cc:FillLoraServerStats:1133: lora network server is enabled

i am using 5.3.3

my script uses paho mqtt to grab messages from the local mqtt server and to send it to the mqtt server in the cloud.

any idea how to ensure stability here?

[Jeff Hatch]

Hello Tom,

The logging from AppManager appears to be normal in the sense that the events you see are just the “appmanager –status” running to report the application status. Is your script generating a pid file?

On the MQTT and Mosquito front. When I have worked with MQTT and Mosquitto, I have run into cases where the MQTT connection will timeout or disconnect regularly. When using libmosquitto with C++, the library seemed to have a reconnect behavior.

In your script do you check to verify that you are still connected and maintain the connection when it becomes disconnected? That is one possibility that would cause your app to stop working.

Thank You,

Jeff

[Tom Z]

thanks for the quick reply Jeff

We are using Python for the custom app. Actually when I log in to the UI, the app is running, and I see it is subscribed even to the mqtt broker.

Is your script generating a pid file?

yes we are.

question: can we restart the app from within the app?

this way i can publish and subscribe to /test every 5 min and if it fails I can restart the script

your thoughts?

[Jeff Hatch]

There are some options for restarting the app. The app-manager program can for one. The “app-manager –command restart …” command actually runs the Start script with the restart argument.

If you want to skip using app-manager you could use the “Start restart” directly, but app-manager then may not accurately capture the status of the application.

So, from within your application you could use a call to app-manager to restart, making sure to background app-manager.

[Author]

Posts