Script triggered by API not executed properly

[h1ghrise]

Hi Mikrotik Community.
im using the Community Script to update Containers from this post (http://forum.mikrotik.com/t/easy-container-update-script/172741/6) to update my Home Assistant instance.

This works really well, when executed on the Mikrotik (RB5009) itself.
In Home Assistant, I built an automation, which utilizes the Mikrotik API to trigger the script.
Unfortunately when trigged via API, the Script behaves differently:

Triggered via API:

 13:26:47 script,info Container update: Container HomeAssistant update started
 13:26:47 script,warning Container update: Container HomeAssistant is running, stopping container
 13:26:58 system,info,account user h1ghrise logged out from 10.10.20.2 via api

Do scripts get executes differently, when triggered via API? I cannot reproduce this behavior.
No further entries. The Container is stopped, and nothing happens.

Triggered on the Mikrotik directly:

 13:49:38 script,info Container update: Container HomeAssistant update started
 13:49:38 script,warning Container update: Container HomeAssistant is running, stopping container
 13:49:44 system,info,account user h1ghrise logged out from 10.10.20.2 via api
 13:49:49 script,info Container update: Container HomeAssistant stopped
 13:49:49 container,info,debug removing files, container f934a903-152d-4bdc-a04f-944b8e15a442
 ...

the corresponding code in the script:

:if ($contStatus != "stopped") do={
  :if ($contStatus = "running") do={
    :log warn "$($logPrefix)Container $contComment is running, stopping container"
    :set contStarted true
    stop $contId
  }

  :local stopTimeoutSec 120
  :local sec 0

  :while (([get $contId]->"status") != "stopped" && $sec <= $stopTimeoutSec) do={
    :delay 1
    :set sec ($sec + 1)
  }

  :if ($sec > $stopTimeoutSec) do={ $abortWithMessage ("container $contComment stop timed out, aborting") logPrefix=$logPrefix }
  :log info "$($logPrefix)Container $contComment stopped"
}

[optio]

Glad that you find it useful, I did additionally some small changes to print out messages in terminal, not just in log and moved config vars on top for convenience, but core of script logic remains as in linked topic from OP, here is my latest ver:

:global GcontainerUpdate do={
# After ROS upgrade check below if something has changed
# ------------------------------------------------------
# validAddArgs - array of container add command argument names which are named exact as config property names
  :local validAddArgs ( "cmd", "comment", "dns", "domain-name", "entrypoint", "envlist", "hostname", "interface", "logging", "mounts", "root-dir", "start-on-boot", "workdir" )
# replaceArgs - key-value array for mapping container add command argument name from different config property name,
# where key is config property name and value is argument name
  :local replaceArgs { "tag"="remote-image" }
# addCmd - ROS CLI container add command
  :local addCmd "/container add"
# ------------------------------------------------------
# stopTimeoutSec - container stop wait timeout in seconds
  :local stopTimeoutSec 120
# extrTimeoutSec - container download/extract wait timeout in seconds, rise if not enough (1800 = 30min) on slow network or device
  :local extrTimeoutSec 1800
# logPrefix - script log record prefix
  :local logPrefix "Container update: "

  :local abortWithMessage do={
    :log error "$($logPrefix)Error - $1"
    :error $1
  }

  :local logWithMessage do={
    :if ($level = "W") do={ :log warn "$logPrefix$1" } else={ :log info "$logPrefix$1" }
    :put "[$level] $1"
  }

  :local contComment $1

  /container
  :local contId [find where comment=$contComment]
  :if ($contId = "") do={ $abortWithMessage ("container $contComment not found, aborting") logPrefix=$logPrefix }

  :local contStatus ([get $contId]->"status")
  :if ($contStatus = "extracting") do={ $abortWithMessage ("container $contComment is extracting, aborting") logPrefix=$logPrefix }

  $logWithMessage ("Container $contComment update started") logPrefix=$logPrefix level="I"
  :local contStarted false

  :if ($contStatus != "stopped") do={
    :if ($contStatus = "running") do={
      $logWithMessage ("Container $contComment is running, stopping container") logPrefix=$logPrefix level="W"
      :set contStarted true
      stop $contId as-value
    }

    :local sec 0

    :while (([get $contId]->"status") != "stopped" && $sec <= $stopTimeoutSec) do={
      :delay 1
      :set sec ($sec + 1)
    }

    :if ($sec > $stopTimeoutSec) do={ $abortWithMessage ("container $contComment stop timed out, aborting") logPrefix=$logPrefix }
    $logWithMessage ("Container $contComment stopped") logPrefix=$logPrefix level="W"
  }

  $logWithMessage ("Removing old and adding new container $contComment") logPrefix=$logPrefix level="I"
  :local cont [get $contId]
  remove $contId
  :delay 5

  :local escapeStr do={
    :local strLen [:len $1]
    :local escStr ""

    :for i from=0 to=($strLen - 1) do={
      :local chr [:pick $1 $i ($i + 1)]

      :if ($chr = "\$") do={ :set escStr "$escStr\\\$" } else={
        :if ($chr = "\\") do={ :set escStr "$escStr\\\\" } else={
          :if ($chr = "\"") do={ :set escStr "$escStr\\\"" } else={
            :set escStr "$escStr$chr"
          }
        }
      }
    }

    :return "\"$escStr\""
  }

  :local arrayToStr do={
    :local arrLen [:len $1]
    :local strArr "("

    :for i from=0 to=($arrLen - 1) do={
      :local item [:pick $1 $i]

      :if ([:len $strArr] > 1) do={ :set $strArr "$strArr," }
      :if ([:typeof $item] = "str") do={
        :set $strArr "$strArr$([$escapeStr $item])"
      } else={
        :set $strArr "$strArr$item"
      }
    }

    :return "$strArr)"
  }

  :local escapeValue do={
    :if ([:typeof $1] = "str") do={ :return [$escapeStr $1] }
    :if ([:typeof $1] = "array") do={ :return [$arrayToStr $1 escapeStr=$escapeStr] }
    :if ([:typeof $1] = "bool") do={:if ($1) do={ :return "yes" } else={ :return "no" }}
    :return $1
  }

  :foreach k,v in=$cont do={
    :if ([:len $v] != 0) do={
      :if ([:find $validAddArgs $k] >= 0) do={
        :set addCmd "$addCmd $k=$([$escapeValue $v convertBool=$convertBool escapeStr=$escapeStr arrayToStr=$arrayToStr])"
      } else={
        :local rk ($replaceArgs->"$k")
        :if ([:typeof $rk] != "nothing") do={ :set addCmd "$addCmd $rk=$([$escapeValue $v escapeStr=$escapeStr arrayToStr=$arrayToStr])" }
      }
    }
  }

  :execute "$addCmd" as-string
  :set contId [find where comment=$contComment]
  :if ($contId = "") do={ $abortWithMessage ("unable to add container $contComment, check add command: $addCmd") logPrefix=$logPrefix }

  :local sec 0

  :while (([get $contId]->"status") = "extracting" && $sec <= $extrTimeoutSec) do={
    :delay 1
    :set sec ($sec + 1)
  }

  :if ($sec > $extrTimeoutSec) do={ $abortWithMessage ("container $contComment extract wait timed out, something is failed or slower than expected") logPrefix=$logPrefix }
  :if ($contStarted) do={
    $logWithMessage ("Starting container $contComment") logPrefix=$logPrefix level="I"
    start $contId as-value
  }

  $logWithMessage ("Container $contComment update finished") logPrefix=$logPrefix level="I"
}

Regarding issue, could be some permissions, can you manually create and run container over API and just with script is failing?
If is not permissions issue, could be issue with payload serialization and escaping, try to log $addCmd var before :execute command (:log info $addCmd) and see if is different for same container configuration when executed from terminal and over API.
For further troubleshooting help specify if is this related to legacy API or REST API.

[Amm0]

Assuming you’re using REST or “native API” to run /system/script with update code, might be easy to try setting “Don’t Check Permissions” on that script to see if it works then. And/or make sure the script owner is same as the user you’re using to login with REST/API.

[h1ghrise]

Thanks both of you for your hints and feedback.
First, thanks for the updated version. In the OP, the $contComment was supplied in the script itself:

:local contComment "CommentToIdentifyContainer"

Now its supplied with an argument?

:local contComment $1

Call me stupid, but where do i supply that?

For the issue related part: I checked the permissions, and the script has not set the “don’t require permissions” flag set. I set it and tried again withe the original script. Did not change anything.
Also the user triggering the API call is the same who created the script.
In general, Im using the regular API via an HACS Plugin: https://github.com/tomaae/homeassistant-mikrotik_router (using master branch, as default version in HACS does not work with 7.12+)

[optio]

:local contComment "CommentToIdentifyContainer"

Now its supplied with an argument?

:local contComment $1

Call me stupid, but where do i supply that?

That’s also script change but forgot to mention, whole script code is added into global var as function which accepts container comment as argument ($1). It is more convenient when you need to update multiple containers, now there is no need to edit script to change container comment or have multiple same scripts for each container update, eg.:

> /system/script/run <container_update_script_name>
> $GcontainerUpdate "<some container1 comment>"
> $GcontainerUpdate "<some container2 comment>"
...

Running this script can be also added to startup scheduler so that you will always have $GcontainerUpdate on disposal when needed since it is not needed to re-run script to add global var. again unless script code has changed (or this global var. deleted).
But if you want to behave as prev. script, just delete first line “:global GcontainerUpdate do={”, last line closing bracket “}” and replace $1 with container comment for contComment var. value as you have now.

For the issue related part: I checked the permissions, and the script has not set the “don’t require permissions” flag set. I set it and tried again withe the original script. Did not change anything.

Try to log execute string from $addCmd variable as mentioned in prev. post and post both when is success from terminal and when is not from API. If are the same could be some issue with :execute command executed over API then…

P.S.
As I see in this code https://github.com/tomaae/homeassistant-mikrotik_router/blob/master/custom_components/mikrotik_router/mikrotikapi.py#L312 it just runs already created script on ROS, then it shouldn’t be issue with script content, like escaping (I initially assumed that script is sent from remote over API), I guess this is related to some user restrictions or bug in ROS.

[h1ghrise]

Hi, thanks for your clarification. For now, I removed the function wrapper - I only want to update Home Assistant.
Also, I have added some verbose logging, to pinpoint the issue:

  :while (([get $contId]->"status") != "stopped" && $sec <= $stopTimeoutSec) do={
    :delay 1
    $logWithMessage ("Container $contComment is still running, retrying...") logPrefix=$logPrefix level="W"
    :set sec ($sec + 1)
  }

It seems, that the part below the container stop check, never gets executed:

 20:56:50 script,info Container update: Container HomeAssistant update started
 20:56:50 script,warning Container update: Container HomeAssistant is running, stopping container
 20:56:51 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:56:52 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:56:53 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:56:54 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:56:55 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:56:56 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:56:57 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:56:58 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:56:59 script,warning Container update: Container HomeAssistant is still running, retrying...
 20:57:00 script,warning Container update: Container HomeAssistant is still running, retrying...

Log stops when container is stopped, but does not reach (?) the part, where it should log the removing of the old container:

$logWithMessage ("Removing old and adding new container $contComment") logPrefix=$logPrefix level="I"

[optio]

There is no either log “Container update: Container Container HomeAssistant stopped”, (line: $logWithMessage (“Container $contComment stopped”) logPrefix=$logPrefix level=“W”) which means can be timeouted by check in line above :if ($sec > $stopTimeoutSec) do={ $abortWithMessage (“container $contComment stop timed out, aborting”) logPrefix=$logPrefix } but there is no error log “Container update: container Container Containerstop timed out, aborting” so I doubt that is the case, more likely script is terminated while was in wait loop for some reason.
How long stopping this container takes?

Maybe API connection is closed while script is running and ROS terminates script executed over API when closed, if that’s the case try if this hack works - create additional script for executing over API which pefrforms script run async with :execute command:

:execute "/system/script/run <container-update-script-name>"

[h1ghrise]

This is it. As container gets stopped, api user is logged out and script terminated. Will try your suggested hack. Thanks a lot for pointing me in the right direction.

Update: yes, its working Update gets carried out as it should. Thanks