0

I know there have been a lot of similar questions, but for the life of me I can't figure out what's wrong! I have a script that forwards a port via ssh tunnel, and it works pretty fine, and I want to run it as a service on startup using systemd. I already have other services running on my Pi as systemd services, and they work well, so I can't figure out why this one is not. I'm using Raspbian Jessie (server, no gui, headless Pi).

So, the unit file is as follows:

[Unit]
Description=SSH tunnel for DomoPro
After=multi-user.target sshd.service network.target

[Service]
Type=idle
ExecStart=/usr/bin/python /usr/bin/pyScripts/mkTunnel.py
ExecStop=/usr/bin/python /usr/bin/pyScripts/rmTunnel.py
StandardOutput=journal

[Install]
WantedBy=multi-user.target

and the python script, in case it's necessary, is as follows:

#!/usr/bin/python
import MySQLdb
from time import time,sleep
from subprocess import Popen,call,PIPE
import pycurl
from StringIO import StringIO
import json
from math import floor

print("DomoPro Tunnel Service")

def getSerial():
    cursor.execute("SELECT value FROM config WHERE var='serialKey'")
    cfg = cursor.fetchone()
    return cfg['value']

def setPort(port):
    sqlupdt = "UPDATE config SET value = '{0}' WHERE var='remotePort'".format(port)
    cursor.execute(sqlupdt)

def savePID(tunnelPID):
    sqlupdt = "UPDATE config SET value = '{0}' WHERE var='tunnelPID'".format(tunnelPID)
    cursor.execute(sqlupdt)

def clearPID():
    sqlupdt = "UPDATE config SET value = '' WHERE var='tunnelPID'"
    cursor.execute(sqlupdt)

def getTunnelData(serialKey):
    from urllib import urlencode
    ans = StringIO()
    serverURL = "server_address/phpfile.php"

    data_post = urlencode({"serialKey": serialKey})

    curl = pycurl.Curl()
    curl.setopt(curl.URL, serverURL)
    curl.setopt(curl.WRITEFUNCTION, ans.write)
    curl.setopt(curl.USERAGENT, "Some custom useragent")
    curl.setopt(curl.FAILONERROR, 1)
    curl.setopt(curl.CONNECTTIMEOUT, 10)
    curl.setopt(curl.HTTPHEADER,['Accept: application/json'])
    curl.setopt(curl.POST, 1)
    curl.setopt(curl.POSTFIELDS, data_post)
    try:
        curl.perform()
    except pycurl.error:
        return (False,False,False)

    curl.close()

    try:
        data = json.loads(ans.getvalue())
    except ValueError:
        return False
    else:
        (auth,port,isActive) = data['auth'], data['port'], data['isActive']

        if auth == "OK":
            return (auth,port,isActive)
        else:
            return (auth,False,False)

def openTunnel(port):
    if port:
        tunnel = call(['ssh','-fNq','-o','ConnectTimeout=5','-o','BatchMode=yes','-o','StrictHostKeyChecking=no','-o','ExitOnForwardFailure=yes','-R','{0}:localhost:443'.format(port),'user@server'])
        return tunnel
    else:
        return 1

def getpsPID():
    objPID = Popen('ps -C "ssh -fNq" -o pid=', shell=True, stdout=PIPE, stderr=PIPE)
    PID = objPID.communicate()[0].replace('\n','').replace(' ','')
    return PID

def getdbPID():
    cursor.execute("SELECT value FROM config WHERE var='tunnelPID'")
    cfg = cursor.fetchone()
    return cfg['value']

def makeTunnel():
    '''
    Return Codes:
        0: Ok
        1: Failed
        2: Not Active
        3: Auth Err
        4: Conn Err
    '''
    print("Opening tunnel...")
    serialKey = getSerial()
    (auth,port,isActive) = getTunnelData(serialKey)
    if auth == "OK":
        if isActive:
            setPort(port)
            tunnel = openTunnel(port)
            if not tunnel:
                tunnelPID = getpsPID()
                savePID(tunnelPID)
                print("Tunnel open")
                return 0
            else:
                clearPID()
                print("Tunnel failed")
                return 1
        else:
            setPort(0)
            clearPID()
            print("DomoPro Remote not active")
            return 2
    elif auth == "ERROR":
        setPort(0)
        clearPID()
        print("Auth error")
        return 3
    else:
        setPort(0)
        clearPID()
        print("Connection failed")
        return 4

def checkTunnel():
    print("Checking tunnel...")
    dbPID = getdbPID()
    psPID = getpsPID()
    if psPID:
        if dbPID != psPID:
            savePID(psPID)
        print("Tunnel open, PID:{}".format(psPID))
        return 0
    else:
        clearPID()
        print("Tunnel closed")
        return 1

db = MySQLdb.connect(   host="localhost",
                        user="user", 
                        passwd="pass", 
                        db="db")
db.autocommit(True)
cursor = db.cursor(MySQLdb.cursors.DictCursor)

tunnelState = checkTunnel()
if tunnelState:
    tunnelState = makeTunnel()
ts = time()
while True:
    currts = time()
    if (tunnelState == 0 or tunnelState == 1):
        timeoff = 120
        if (currts - ts) > timeoff:
            tunnelState = checkTunnel()
            if tunnelState:
                tunnelState = makeTunnel()
            ts = time()
        else:
            diff = timeoff - floor(currts - ts)
            print("Sleeping for {}s...".format(diff))
            sleep(diff)
    elif tunnelState == 2:
        timeoff = 3600
        if (currts - ts) > timeoff:
            tunnelState = makeTunnel()
            ts = time()
        else:
            diff = timeoff - floor(currts - ts)
            print("Sleeping for {}s...".format(diff))
            sleep(diff)
    elif tunnelState == 3:
        timeoff = 86400
        if (currts - ts) > timeoff:
            tunnelState = makeTunnel()
            ts = time()
        else:
            diff = timeoff - floor(currts - ts)
            print("Sleeping for {}s...".format(diff))
            sleep(diff)
    elif tunnelState == 4:
        timeoff = 300
        if (currts - ts) > timeoff:
            tunnelState = makeTunnel()
            ts = time()
        else:
            diff = timeoff - floor(currts - ts)
            print("Sleeping for {}s...".format(diff))
            sleep(diff)

cursor.close()

I also tried adding it to crontab using @reboot to no avail.

The script works flawlessly when run from command line.

You may notice there's another script running on service stop. It actually runs ok.

EDIT:

I followed Goldilocks' guide and wrapped the script like this:

#!/bin/bash
# Wrapper for mkTunnel.py

exec &>> /home/pi/log/tunnel.log
echo $(date)

# Fork/exec
(
        exec /usr/bin/python /usr/bin/pyScripts/mkTunnel.py
) &>> /home/pi/log/tunnel.log

exit 0

And it runs ok, but since my python script keeps running in background, and I guess that systemd is expecting an exit code, it shows an error message Job for tunnel.service failed. The journal shows the following:

Starting SSH tunnel for DomoPro...
tunnel.service start operation timed out. Terminating.
Failed to start SSH tunnel for DomoPro.
Unit tunnel.service entered failed state.

My current unit file is this:

[Unit]
Description=SSH tunnel for DomoPro
After=multi-user.target sshd.service network.target

[Service]
Type=forking
GuessMainPID=no
ExecStart=/usr/bin/pyScripts/tunnel.sh
ExecStop=/usr/bin/python /usr/bin/pyScripts/rmTunnel.py
StandardOutput=journal
StandardError=journal

[Install]
WantedBy=multi-user.target

How can I tell systemd not to timeout (or not to expect an exit code)?

EDIT 2:

It's working!! I forgot to remove verbosity from ssh and that was causing it to remain open, not returning an exit status for systemd. Thanks @goldilocks ;)

  • 1
    ANY script you run on startup NEEDS to have fully qualified paths to executables. This includes any code called by the script. – Milliways May 17 '17 at 00:01
  • 1
    Is not running or is it not working? – otoomey May 17 '17 at 09:12
  • "You may notice..." -> So in fact it does run, evidently it just does not accomplish what you want. You have some logging to StandardOutput, have you bothered looking at (or expanding) that? You should also attach StandardError, I imagine curl and some of those other python bits complain there on failure (unless of course you catch those exceptions and throw any message away...I'm not a python user but it looks to me like you do that at least once). – goldilocks May 17 '17 at 11:01
  • @goldilocks It doesn't seem to be running. I'm redirecting the output to systemd's journal, and the print statements should be there, but they're not. The ExecStop script does run, so I just don't understand what's wrong. I'll give it a try with redirecting StandardError to the journal as well to check for any errors, but it would really be a surprise since the script works pretty fine. – Christian Rodriguez May 18 '17 at 14:30
  • I'm a hack with systemd: I just wrap everything I want to do in a little fork-exec shell script ( exec whatever ) &> /var/log/mine/whatever.log and use Type=forking. You can then elaborate that wrapper (make sure the path is set appropriately, echo "hello world I'm here", etc). Systemd has tidier ways to do all that so hackish -- but I do get everything to work this way and it's easy to see where it went wrong if it doesn't. There is always a reason ;) Have you looked at the output from systemctl status whatever? – goldilocks May 18 '17 at 14:40
  • @goldilocks I redirected StandardError and no errors are showing. I do believe that the script is not running. – Christian Rodriguez May 18 '17 at 14:41
  • That systemctl status report should show a historical process tree and give you a clue about when what failed. It includes stuff that is not send to the journal. – goldilocks May 18 '17 at 14:42
  • @Milliways You mean the code calling for ssh and ps and such? Gonna give it a try. – Christian Rodriguez May 18 '17 at 14:42
  • Path problems are easy to spot via the shell wrapper -- you will get command not found, etc. You need to have that level of debugging in place one way or another. – goldilocks May 18 '17 at 14:44
  • @goldilocks It always shows that the script is active (running), and the process tree shows the script running and the PID for the python process. – Christian Rodriguez May 18 '17 at 14:45
  • If there's a pid you can check it if it is really still running (ps -p [pid]). If it is -- there you go. You need to work more logging in. The bigger and more complex pieces of code I write, the more I've come to depend on that to streamline the debugging process. I'm sure I'm not alone in that, either, lol. If your process is running, you need to step through your code and find places for it to report significant changes in state (stages of initialization, etc.), even when nothing is wrong. – goldilocks May 18 '17 at 15:04
  • Start by creating a simple function that adds a timestamp to each message and use a dedicated file instead of syslog. Consider also implementing a verbose logging mode, expressly for debugging (then you can easily turn off the trivial messages). There's an elaboration of the shell wrapper concept here: https://raspberrypi.stackexchange.com/q/40493/5538 – goldilocks May 18 '17 at 15:06
  • @goldilocks Yeah, I'm trying to wrap it in an exec to see if it works. I'll get back with news as soon as I get 'em ;) – Christian Rodriguez May 18 '17 at 15:10
  • @goldilocks Ok, got it working, thanks to you! Please post your answer so I can accept it ;) – Christian Rodriguez May 18 '17 at 19:29
  • I'll just close it as a duplicate, unless you would like this reopened so you can post an answer yourself. Having a dupe like this is a good one as an example -- other questions can be closed as a dupe of this one, so people end up reading them both (I read through a chain like that probably several times a day on Stack Overflow). – goldilocks May 19 '17 at 13:52

0 Answers0