Habapp job execution time

Apps & Services 3rd Party
1

Hi,
yesterday I created a scheduler rule with habapp.
The rule as it is runs one time per hour and works fine.
But in the log I found some warning that the job itself runs to long.
Here is the example:

2022-10-31 13:53:25,914] [ HABApp.Worker] WARNING | Execution of MySchedule.run_every_3600s took too long: 23.25s
[2022-10-31 13:53:25,979] [ HABApp.Worker] WARNING | ncalls tottime percall cumtime percall filename:lineno(function)
[2022-10-31 13:53:25,979] [ HABApp.Worker] WARNING | 1 0.101 0.101 23.246 23.246 /home/pi/habapp/files/rules/schedule.py:48(run_every_3600s)

Normally it needs about 30 s to execute.

Now my Question: Because it is only a warning, can I just use it as it is,
or is there a better way for such long running(~30s) jobs?
Is there a way to suppress this special warning? If suppressed it will not fill up my logs.

2

That’s a very long job! Can you break it up? Or, put it in a thread?
HABApp will be stalled for 30 seconds while executing your job, where light switches and everything else will not work for the duration of the long job.

3

It’s a warning because 30secs is quite a long time and if you do this 10 x at the same time HABApp will run out of threads.
It it’s only once every hour you can ignore the warning.
Do you interact with openhab from the function or is it just interacting with another system?
If it’s the latter a possible solution might be to put it in a extra script and run it with self.execute_subprocess

4

Yes you’re right.
In my case it is the last case. I do not interact with openhab.
I did some test to check my network connectivity.
For that I use speedtest-cli.

Before HabApp I run this as a cron job on the pi and just check log messages.
With HabApp my thougts were: Now I can do this as a job in habapp and store the results
in openhab. So I have a visualization.

I will try you’re self.execute_subprocess.

5

You’ll get the output of the process.
Just print the results with “print” as a json and read it back in with HABApp.
That way you can still store the speed results in openHAB.

6

Hi Sebastian,
I give it a try. But one some reason I did not see, it will not work.

Here is my Rule:

        self.run.every(datetime.timedelta(seconds=10), 60, self.run_every_60s, 'arg 1', asdf='kwarg 1')

    def run_every_60s(self, arg, asdf = None):
        log.info('======run 60s rule...')
        act_time = datetime.datetime.now().replace(microsecond=0)
        print(f'Speedtest started: {act_time} ')
        myOutput=self.execute_subprocess( self.speedtest_finished, 'python ../lib/myspeedtest.py', arg, True)
        print(myOutput)

   def speedtest_finished(self, arg):
        act_time = datetime.datetime.now().replace(microsecond=0)
        log.info(f'Speedtest finished: {act_time} ')
        print(f'Speedtest finished: {act_time} ')

and the SpeedTest is in the files/lib subdir, called myspeedtest.py

def run_speedtest():
    myTimeStart = datetime.datetime.now()
    print(f'Start:{myTimeStart}')
    test = speedtest.Speedtest()
    test.get_servers()
    best = test.get_best_server()
    download = test.download()/1024/1024
    upload = test.upload()/1024/1024
    myTimeEnd = datetime.datetime.now()
    print(f'End:{myTimeEnd}')
    runTime = myTimeEnd - myTimeStart
    print(f'End:{runTime.total_seconds()}')

    print(f'download={download}')
    print(f'upload={upload}')
    print(f'ping={test.results.ping}')


if __name__ == '__main__':
    run_speedtest()

The 60s job is called correctly.
There is the correct print on the terminal.
Also the finish callback function is called(speedtest_finished). The print is also in the terminal.
But the Timestamp between both prints is 0 , so speedtest never runs.

If I run python myspeedtest.py from the terminal it works.

Here ist the output from ther terminal

Speedtest started: 2022-11-03 15:58:04 
None
Speedtest finished: 2022-11-03 15:58:04 
Speedtest started: 2022-11-03 15:59:04 
None
Speedtest finished: 2022-11-03 15:59:04 
Speedtest started: 2022-11-03 16:00:04 
None
Speedtest finished: 2022-11-03 16:00:04

So were did i the error?

7

Could you include the printed output in your post please?

8

done

9

Could you print arg of speedtest_finished

10

Isn’t it that from the every call?
I just copy it from the examples.
Actually I do not use them.
Will print them.later. actually I’m doing some Sport

11

No worries I’m not in a hurry

    def speedtest_finished(self, arg):
        act_time = datetime.datetime.now().replace(microsecond=0)
        log.info(f'Speedtest finished: {act_time} ')
        print(f'Speedtest finished: {act_time} ')

        print(arg)   # <---------- This one is missing
12

The first arg 1 is the one inside
run_every_60s(self, arg, asdf = None):

The <ProcessIn inside
def speedtest_finished(self, arg):

arg 1
Speedtest started: 2022-11-03 21:47:29 
None
Speedtest finished: 2022-11-03 21:47:29 
<ProcessInfo: returncode: -1, stdout: None, stderr: expected str, bytes or os.PathLike object, not bool>
13

your call is wrong:

You have to split the arguments. Also your mixture of positional arguments and keyword arguments makes no sense.
Try this:

myOutput=self.execute_subprocess( self.speedtest_finished, 'python', '../lib/myspeedtest.py', capture_output=True)
14

Ok, that looks better.
But actually it looks that the started process did not run in the virtual enviroment of
the habapp.
There comes an error that the module speedtest is not found.

Should the subprocess automatically runs also I’m the correct venv,or did I need to install needed modules in the main is?

If i run the python script in the venv directly with python…/lib/myspeedtest.py everything works

15

Neither, you need to specify the proper interpreter. Use sys.executable instead of “python”.

I’ll release a new version next week or the week after which simplifies the process and module handling a lot. So if you’re patient you can just wait for the new version or you can try out the dev branch.

16

Hi, that’s not the problem. I could be Patience.

But for my understanding. Specifying the correct python version is not solution.
The process needs to run in the virtual environment or did I understand something wrong?

If I start thensxriot from a simpke Terminal Session with python myspeedtest.py it will also fail.

But doing a source activate in the habap dir Starts the venv. After that the same python myspeedtest.py works.

But that’s just for my knowledge.
I can wait to the next Version

17

new implementation
Dev installation

I’d love to get feedback so it would be nice if you could try it out (can also be your main machine).

18

Ok, i will try this evening, when I’m at home.

Sent you a feedback after that test.

19

Ok, now I tried it.
Looks that it works:

Here is the actual code

   def run_every_60s(self, arg, asdf = None):
        log.info('======run 60s rule...')
        print(arg)
        act_time = datetime.datetime.now().replace(microsecond=0)
        print(f'Speedtest started: {act_time} ')
        myOutput = self.execute_python( self.speedtest_finished,
                                        'c:/Development/Smarthome/dev_habapp/files/lib/myspeedtest.py',
                                        'arg1_for_script')

        print(myOutput)
        act_time = datetime.datetime.now().replace(microsecond=0)
        print(f'Speedtest finished main: {act_time} ')

And here the callback

    def speedtest_finished(self, module_output: str):
        act_time = datetime.datetime.now().replace(microsecond=0)
        log.info(f'Speedtest finished: {act_time} ')
        print(module_output)
        print(f'Speedtest finished callback: {act_time} ')

and here the printing

arg 1
Speedtest started: 2022-11-04 20:56:45
<Future at 0x2ae486542e0 state=pending>
Speedtest finished main: 2022-11-04 20:56:45
Start:2022-11-04 20:56:46.430922
End:2022-11-04 20:57:14.039320
End:27.608398
download=227.81391553841962
upload=24.188108780406576
ping=31.484

Speedtest finished callback: 2022-11-04 20:57:14

before the Speedtest finished callback and before Speedtest finished main
is the print of the outputs. But there is nothing!

So it looks, but the output is not collected, or could not be printed.

Also using a relatic path in self.execute_python is not working.
I have to use the full path
c:/Development/Smarthome/dev_habapp/files/lib/myspeedtest.py

20

Output looks good to me!

I don’t understand your doubts. Could you rephrase?

This is the time to start the child process (which is maybe 10 - 100ms):

Speedtest started: 2022-11-04 20:56:45
<Future at 0x2ae486542e0 state=pending>
Speedtest finished main: 2022-11-04 20:56:45

The process gets started and once it finishes the output is properly loaded in HABApp (through the callback):

Start:2022-11-04 20:56:46.430922
End:2022-11-04 20:57:14.039320
End:27.608398
download=227.81391553841962
upload=24.188108780406576
ping=31.484

Now you just have to create a dict and use print(json.dumps((my_result_dict)) as the output in your script. Parsing in on the HABApp side is done with json.loads. Easy peasy :wink: