Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

High CPU usage on streaming plugin #161

Closed
xilopaint opened this issue Feb 9, 2021 · 42 comments
Closed

High CPU usage on streaming plugin #161

xilopaint opened this issue Feb 9, 2021 · 42 comments
Assignees
Milestone

Comments

@xilopaint
Copy link
Contributor

xilopaint commented Feb 9, 2021

I'm facing issues with %CPU when running my streaming plugin. After some tests I came to the conclusion that the CPU usage can increase a lot if I print more than a single-line output in SwiftBar.

This is my original print function in the Python script:

print(
    '~~~',
    f'{coin}: {roi_fmt} ({roe_fmt}%) | color={color}',
    '---',
    f'Side: {side}',
    f'Entry Price: {entry_price}',
    f'Last Price: {last_price}',
    f'Quantity: {qty}',
    '---',
    f'Take Profit: {take_profit}',
    f'Stop Loss: {stop_loss}',
    sep='\n',
    flush=True
)

With the above multi-line output I had a lot of issues with high CPU usage which can get 100% sometimes apart of the app hanging, so I changed to this one-line output in order to avoid issues:

print(
    '~~~',
    f'{coin}: {roi_fmt} ({roe_fmt}%) | color={color}',
    sep='\n',
    flush=True
)

Another issue I have been facing is that the output in SwiftBar constantly disappear for a second or two during the stream as you can see in the following gif:

main_large

@melonamin
Copy link
Contributor

Can you share the full script?

@xilopaint
Copy link
Contributor Author

xilopaint commented Feb 9, 2021

Hey, the 100% CPU usage and the app hanging seems to have been an issue with my script that I just fixed. Even so, the point related to higher CPU usage in multi-line outputs seems to remain valid according to my tests.

Here's the script: https://gist.github.com/xilopaint/6e3cae49c8b4b75b135fa8a554001274

You might be more interested in the print_stream_data function.

@melonamin
Copy link
Contributor

I don't think there is a problem in Swiftbar, here is my test:

#!/usr/bin/env python3
# <swiftbar.type>streamable</swiftbar.type>
import time
import random

while True:
    number = random.choice(range(10))
    print(number)
    print("---")
    for x in range(0, 20):
        print("Menu Line %d" % (x))
    print("End of menu", flush=True)
    time.sleep(0.1)
    print('~~~')

Pretty big menu, updates every tenth of a second and consumes less than 8% of CPU. In practice I don't think it's reasonable to update the menu at this rate.

As for the second issue, the only reason for flickering like that is a gap in output, meaning you clean the menu with ~~~ and then have nothing for a while.

@xilopaint
Copy link
Contributor Author

xilopaint commented Feb 10, 2021

Pretty big menu, updates every tenth of a second and consumes less than 8% of CPU. In practice I don't think it's reasonable to update the menu at this rate.

I don't agree it isn't a realistic rate. With a single line output and a 0.01 second I also get less than 8% of CPU (I would say an average of ~2.5% according to my observation of activity monitor). The %CPU never really surpasses 7% CPU with a single line output.

On the other hand with the multiline output I got an average of something like 8% and the %CPU surpasses 10% sometimes (and 20% more rarely). Unfortunately I don't know a tool that can calculate a CPU usage average over a certain time.

Honestly, it's not a big deal to me. It's always good if Swiftbar can improve its performance but the severe issues I was facing with CPU usage were not related to SwiftBar but a bug in my script that I fixed after opening this issue.

As for the second issue, the only reason for flickering like that is a gap in output, meaning you clean the menu with ~~~ and then have nothing for a while.

I just found out that the flickering issue was related to #2. What was happening is that the streaming plugin was changing its position in menu bar and I couldn't see it because I use Bartender. After quitting Bartender and moving the plugin to the edge position of the menu bar the flickering issue doesn't happen. Interestingly the issue only occurs with the streaming plugin.

I see there are already some commits regarding #2. Could you provide a build with the fix for me to test with Bartender?

@melonamin
Copy link
Contributor

All this talk about 7% vs 4% vs 8% is not productive, mainly because we are probably running it on different CPUs, my point was that in no way Swiftbar consume a full core(a sign of a bad design somewhere). On the other hand, make frequent UI refresh significantly more efficient will be quite hard, since system API's are not designed to handle it.

I see there are already some commits regarding #2. Could you provide a build with the fix for me to test with Bartender?

I don't think it relates to Bartender, or at least I don't see it on my machine with Bartender. Next build will have some improvements in this area.

@xilopaint
Copy link
Contributor Author

All this talk about 7% vs 4% vs 8% is not productive

I didn't make a comparison of my performance vs yours, but one-line output vs multi-line output on my own CPU.

I don't think it relates to Bartender, or at least I don't see it on my machine with Bartender.

I only have the issue with Bartender. However the issue is not caused by Bartender but by the fact that the plugin constantly changes its location. Bartender only makes it invisible when it moves to the left.

@melonamin
Copy link
Contributor

Check out the latest beta for Bartender fix

@xilopaint
Copy link
Contributor Author

Check out the latest beta for Bartender fix

This part seems fine, but the beta build has broken another plugin I have with this output:

print(f"Buy | refresh=true shortcut=CMD+OPT+B terminal=false bash=\'{__file__}\' param0=BUY param1={symbol} param2={precision}")
print(f"Sell | refresh=true shortcut=CMD+OPT+S terminal=false bash=\'{__file__}\' param0=SELL param1={symbol} param2={precision}")
print(f"Close | refresh=true shortcut=CMD+OPT+P terminal=false bash=\'{__file__}\' param0=CLOSE param1={symbol} param2={precision}")

The script is not being executed on item click nor the shortcut works. Any chance it has something to do with the feature requested at #163?

@melonamin
Copy link
Contributor

Can you reproduce and show me logs from Console.app?

@xilopaint
Copy link
Contributor Author

Can you reproduce and show me logs from Console.app?

default	14:07:39.812171-0300	SwiftBar	Executing script in background... /Users/xxxxx/Developer/SwiftBar/binance_orders.py BUY BCHUSDT 3
error	14:07:40.597374-0300	SwiftBar	Failed to execute script in background /bin/bash: /Users/xxxxx/Developer/SwiftBar/binance_orders.py BUY BCHUSDT 3: No such file or directory

melonamin added a commit that referenced this issue Feb 13, 2021
@xilopaint
Copy link
Contributor Author

Hey @melonamin, I still have the issue with the position of the streaming plugin changing on v1.2.3 beta.

The behavior is the following: if I'm using Bartender, the plugin flickers from time to time and if I don't use it the flicker issue doesn't happen but the plugin changes its position after a few seconds to the left edge of the menu bar.

@melonamin
Copy link
Contributor

Do you have a simple plugin I can run to reproduce it? I can't find a way to trigger this behavior.

@xilopaint
Copy link
Contributor Author

xilopaint commented Feb 13, 2021

This part seems fine, but the beta build has broken another plugin I have with this output:

print(f"Buy | refresh=true shortcut=CMD+OPT+B terminal=false bash=\'{__file__}\' param0=BUY param1={symbol} param2={precision}")
print(f"Sell | refresh=true shortcut=CMD+OPT+S terminal=false bash=\'{__file__}\' param0=SELL param1={symbol} param2={precision}")
print(f"Close | refresh=true shortcut=CMD+OPT+P terminal=false bash=\'{__file__}\' param0=CLOSE param1={symbol} param2={precision}")

This plugin remains broken in v1.2.3 beta 2. I don't get the same error message in console, but the bash parameters are not being passed.

melonamin added a commit that referenced this issue Feb 14, 2021
@xilopaint
Copy link
Contributor Author

xilopaint commented Feb 14, 2021

Do you have a simple plugin I can run to reproduce it? I can't find a way to trigger this behavior.

I finally got a minimal way to reproduce the issue. You only have to install UNICORN Binance WebSocket API and run this plugin:

#!/usr/bin/env python3
# <swiftbar.type>streamable</swiftbar.type>

import random
import time
from unicorn_binance_websocket_api.unicorn_binance_websocket_api_manager import BinanceWebSocketApiManager

binance_websocket_api_manager = BinanceWebSocketApiManager()

while True:
    print('~~~')
    print(random.choice(range(10)), flush=True)
    time.sleep(0.1)

With Bartender running, you will see the plugin flickering on menu bar. Without Bartender running, if you try to move the plugin to another location you will see it moving back to the original location.

If you remove the line binance_websocket_api_manager = BinanceWebSocketApiManager() everything works fine. So the issue lies in this line.

Another detail is that if you quit SwiftBar with this plugin running the Python process keeps running and you have to kill it manually.

Btw, on Terminal I don't have any issues with the script.

@melonamin
Copy link
Contributor

This plugin remains broken in v1.2.3 beta 2. I don't get the same error message in console, but the bash parameters are not being passed.

Please check if you seeing this in the latesr build

@xilopaint
Copy link
Contributor Author

This plugin remains broken in v1.2.3 beta 2. I don't get the same error message in console, but the bash parameters are not being passed.

Please check if you seeing this in the latesr build

Still not working. Do you want me to create a simple script for this case?

@xilopaint
Copy link
Contributor Author

@melonamin the issue with the bash parameters is fixed.

Any thoughts on this other issue?

@melonamin
Copy link
Contributor

melonamin commented Feb 22, 2021

@xilopaint I think issue is a little bit more complex, look at this video - it works fine.
video

I've seen it jump a couple of times, my current theory - maybe it occurs when two plugins try to update menu bar at the same time. Some kind of race or something like that.

I don't think that binance_websocket_api_manager = BinanceWebSocketApiManager() plays any role at all.

Another detail is that if you quit SwiftBar with this plugin running the Python process keeps running and you have to kill it manually.

That's a great catch, fixed

@xilopaint
Copy link
Contributor Author

I've seen it jump a couple of times, my current theory - maybe it occurs when two plugins try to update menu bar at the same time. Some kind of race or something like that.

Have you tried to install the package and run the sample plugin I recommended? I don't see the issue if I remove that line. On the other hand, with BinanceWebSocketApiManager() the issue happens all the time. Please, try it.

@melonamin
Copy link
Contributor

Yes, I’m running your plugin on the demo video

@xilopaint
Copy link
Contributor Author

Yes, I’m running your plugin on the demo video

Weird. On my machine this plugin jumps all the time. Do you think this issue can be fixed in the future or it's too niche?

@melonamin
Copy link
Contributor

What other plugins are you running when you see the issue? Maybe it is a combination...

@xilopaint
Copy link
Contributor Author

What other plugins are you running when you see the issue? Maybe it is a combination...

I have the issue even if this is the only plugin enabled.

melonamin added a commit that referenced this issue Mar 4, 2021
- Content updated through Combine, to avaiod potential race
- Streaming plugin stays in menu bar output is empty
@melonamin
Copy link
Contributor

Hey @xilopaint, can you play with this build please?
SwiftBar.app.zip

@xilopaint
Copy link
Contributor Author

Hey @xilopaint, can you play with this build please?

I don't have much time to test it today, but I'll give you a feedback tomorrow. Thanks!

@xilopaint
Copy link
Contributor Author

xilopaint commented Mar 5, 2021

Hey @xilopaint, can you play with this build please?
SwiftBar.app.zip

I just tested the build. The flickering issue seems to be fixed and the plugin is holding its position on menu bar properly, but I've noticed two things. My streaming plugin is set to only print content when a trade position in Binance is opened. It means the plugin keeps listening the Binance websocket waiting for a position to be opened. Now I see that on this stage the plugin takes up a blank space on menu bar. Is this expected behavior? Another thing is that I can't clear the plugin with ~~~ to make it blank again after the trade position is closed.

This is a sample plugin that I expected to clear the plugin in menu bar after n == 1:

#!/usr/bin/env python3
# <swiftbar.type>streamable</swiftbar.type>
import random
import time

n = 0
while True:
    print('~~~', flush=True)
    if n != 1:
        n = random.choice(range(10))
    print(n, flush=True)
    time.sleep(1)

What actually happens is that the 1 output is never cleared.

melonamin added a commit that referenced this issue Mar 6, 2021
@melonamin
Copy link
Contributor

melonamin commented Mar 6, 2021

Now I see that on this stage the plugin takes up a blank space on menu bar. Is this expected behavior?

Yes, this was a part of the test.

After I spend too much time on this, here is what I've found.

When SwiftBar receives empty string as in input it hides the menu bar item, jumping and flickering was caused by SwiftBar quickly hiding and showing the menubar.

In the recent build I've disabled the hiding for streaming plugins, that's why you don't see flickering/jumping, but at the same time the menu bar item is never hidden, which is no bueno.

Let's see why you had empty strings in the stream:

Script 1:

#!/opt/homebrew/bin/python3
# <swiftbar.type>streamable</swiftbar.type>

import random
import time

while True:
    print('~~~')
    print(random.choice(range(10)), flush=True)
    time.sleep(0.1)

Swiftbar sees output as follows:

"~~~\n0\n"
"~~~\n7\n"
"~~~\n6\n"
"~~~\n0\n"
"~~~\n9\n"
"~~~\n1\n"
"~~~\n4\n"

All good here, each string contains content and the separator, no flickering\jumping.

Script 2(same as Script 1 one but with Behance):

#!/opt/homebrew/bin/python3
# <swiftbar.type>streamable</swiftbar.type>

import random
import time
from unicorn_binance_websocket_api.unicorn_binance_websocket_api_manager import BinanceWebSocketApiManager

binance_websocket_api_manager = BinanceWebSocketApiManager()

while True:
    print('~~~')
    print(random.choice(range(10)), flush=True)
    time.sleep(0.1)

Swiftbar sees output as follows:

"~~~\n7\n"
"~~~\n3\n"
"~~~\n8\n"
"~~~\n2\n"
"~~~\n"
"7\n"
"~~~\n6\n"

See the problem? ~~~\n equals to empty string in SwiftBar's mind - flicker\jumping happens here. Why this is happening with Binance import? I have no clue, scripting language are weird, my best guess is that it somehow mess with the RunLoop and print buffer

You can avoid this if you do something like this, Script 3:

#!/opt/homebrew/bin/python3
# <swiftbar.type>streamable</swiftbar.type>

import random
import time
from unicorn_binance_websocket_api.unicorn_binance_websocket_api_manager import BinanceWebSocketApiManager

binance_websocket_api_manager = BinanceWebSocketApiManager()

while True:
    print("~~~ %s" % random.choice(range(10)), flush=True)
    time.sleep(0.1)

Btw, on Terminal I don't have any issues with the script.

You can't see this in Terminal, because from Terminal's view Script 1 and Script 2 outputs are the same. To address this I've added a special flag to enable streaming plugins debug: defaults write com.ameba.SwiftBar StreamablePluginDebugOutput -bool YES

As for your last question,

What actually happens is that the 1 output is never cleared.

Run this code in terminal, it outputs 1 in the loop, if you want to clear the output you should stop the stream on ~~~

Anyway, I spend too much time on this, and in the end you were right that BinanceWebSocketApiManager() breaks it, but there is no issue in SwiftBar itself. Here is a new build

@xilopaint
Copy link
Contributor Author

xilopaint commented Mar 6, 2021

As for your last question,

What actually happens is that the 1 output is never cleared.

Run this code in terminal, it outputs 1 in the loop, if you want to clear the output you should stop the stream on ~~~

Sorry, my sample code had an indentantion mistake. This was the code with the mistake on line 11:

#!/usr/bin/env python3
# <swiftbar.type>streamable</swiftbar.type>
import random
import time

n = 0
while True:
    print('~~~', flush=True)
    if n != 1:
        n = random.choice(range(10))
    print(n, flush=True)
    time.sleep(1)

This is the right code with the line 11 properly indented:

#!/usr/bin/env python3
# <swiftbar.type>streamable</swiftbar.type>
import random
import time

n = 0
while True:
    print('~~~', flush=True)
    if n != 1:
        n = random.choice(range(10))
        print(n, flush=True)
    time.sleep(1)

Why the above code is not clearing the output 1 if only ~~~ is being printed? You can test it on Terminal and you will see only ~~~ is printed after the output 1.

@xilopaint
Copy link
Contributor Author

P.S.: The question above is not related to the build of your last post.

@melonamin
Copy link
Contributor

Why the above code is not clearing the output 1 if only ~~~ is being printed?
P.S.: The question above is not related to the build of your last post.

Yeah, it was a temporary behavior, should be back to normal now

@xilopaint
Copy link
Contributor Author

xilopaint commented Mar 6, 2021

You can avoid this if you do something like this, Script 3:

#!/opt/homebrew/bin/python3
# <swiftbar.type>streamable</swiftbar.type>

import random
import time
from unicorn_binance_websocket_api.unicorn_binance_websocket_api_manager import BinanceWebSocketApiManager

binance_websocket_api_manager = BinanceWebSocketApiManager()

while True:
    print("~~~ %s" % random.choice(range(10)), flush=True)
    time.sleep(0.1)

How should I rewrite the below print function to fix the issue?

print(
    '~~~',
    f'{coin}: {roi_fmt} ({roe_fmt}) | color={color}',
    '---',
    f'Side: {side}',
    f'Entry Price: {entry_price}',
    f'Last Price: {last_price}',
    f'Quantity: {qty}',
    '---',
    f'Take Profit: {take_profit_output}',
    f'Stop Loss: {stop_loss_output}',
    sep='\n',
    flush=True
)

The function is inside a while loop, btw.

@xilopaint
Copy link
Contributor Author

xilopaint commented Mar 6, 2021

Well, I tested this:

print(
    f'~~~ {coin}: {roi_fmt} ({roe_fmt}) | color={color}',
    '---',
    f'Side: {side}',
    f'Entry Price: {entry_price}',
    f'Last Price: {last_price}',
    f'Quantity: {qty}',
    '---',
    f'Take Profit: {take_profit_output}',
    f'Stop Loss: {stop_loss_output}',
    sep='\n',
    flush=True
)

It fixes the flickering issue but I get weird menus sometimes I click on the plugin. Like this:

Screen Shot 2021-03-06 at 13 14 48

Or this:

Screen Shot 2021-03-06 at 13 23 36

A proper menu should look like this:

Screen Shot 2021-03-06 at 13 18 22

@melonamin
Copy link
Contributor

Look at debug output and adjust accordingly.

To address flickering\jumping issue you need to avoid empty strings in the output and remember that '~~~' is an "empty string". So you don't necessarily need to have the full menu in one print statement.

@xilopaint
Copy link
Contributor Author

xilopaint commented Mar 6, 2021

Look at debug output and adjust accordingly.

What do you mean with debug output? The output in Terminal?

To address flickering\jumping issue you need to avoid empty strings in the output and remember that '~~~' is an "empty string". So you don't necessarily need to have the full menu in one print statement.

I also have the issue using a print statement per line. At the moment I know how to fix the issue for a single line output (just the header). Now my problem lies in dropdown menus (multiple lines output).

@melonamin
Copy link
Contributor

What do you mean with debug output?

From my comment above 👆- To address this I've added a special flag to enable streaming plugins debug: defaults write com.ameba.SwiftBar StreamablePluginDebugOutput -bool YES

Enable this and look into Console.app

@xilopaint
Copy link
Contributor Author

What do you mean with debug output?

From my comment above 👆- To address this I've added a special flag to enable streaming plugins debug: defaults write com.ameba.SwiftBar StreamablePluginDebugOutput -bool YES

Enable this and look into Console.app

I don't think it would be easy to fix it. Sometimes the dropdown menu is well formed and sometimes it's not. Maybe it would be better to drop out the unicorn-binance package and make my own code to consume the websocket.

@xilopaint
Copy link
Contributor Author

@melonamin now I see the weird dropdown menu can happen without the unicorn-binance package.

Running this plugin...

#!/usr/bin/env python3
# <swiftbar.type>streamable</swiftbar.type>
import random
import time

while True:
    foo = random.choice(range(10))
    bar = random.choice(range(10))
    print(
        '~~~',
        f'{foo}',
        '---',
        f'Side: {foo}',
        f'Entry Price: {bar}',
        f'Last Price: {foo}',
        f'Quantity: {bar}',
        '---',
        f'Take Profit: {foo}',
        f'Stop Loss: {bar}',
        sep='\n',
        flush=True
    )
    time.sleep(0.1)

... I can get weird dropdown menus like this:

Screen Shot 2021-03-06 at 16 52 19

Instead of proper dropdown menus like this:

Screen Shot 2021-03-06 at 16 53 09

To reproduce the issue you may need to click repeatedly on the plugin because most of the time the menu is well formed.

@melonamin
Copy link
Contributor

Plugin output looks good, overall looks like an OS rendering bug more than anything else. I'll not invest time into further investigation at this moment

@xilopaint
Copy link
Contributor Author

You can close this issue if you want, @melonamin. Thanks for your work on streaming plugins!

@melonamin melonamin self-assigned this Mar 7, 2021
@melonamin melonamin added this to the 1.2.3 milestone Mar 7, 2021
@xilopaint
Copy link
Contributor Author

Hey @melonamin, just to let you know that I've found a workaround to the bug with BinanceWebSocketApiManager(). Look:

#!/usr/bin/env python3
# <swiftbar.type>streamable</swiftbar.type>
import contextlib
import os
import random
import time
from unicorn_binance_websocket_api.unicorn_binance_websocket_api_manager import BinanceWebSocketApiManager


with open(os.devnull, 'w') as f, contextlib.redirect_stdout(f):
    binance_websocket_api_manager = BinanceWebSocketApiManager()

while True:
    print('~~~')
    print(random.choice(range(10)), flush=True)
    time.sleep(0.1)

@xilopaint
Copy link
Contributor Author

xilopaint commented Apr 13, 2021

Nevermind, the latest release of unicorn-binance-websocket-api (v1.30.0) has explicitly added support for SwiftBar!

https://github.com/oliver-zehentleitner/unicorn-binance-websocket-api/releases/tag/1.30.0

From now on all the user needs to do is set the disable_colorama parameter to True:

#!/usr/bin/env python3
# <swiftbar.type>streamable</swiftbar.type>
import random
import time
from unicorn_binance_websocket_api.unicorn_binance_websocket_api_manager import BinanceWebSocketApiManager


binance_websocket_api_manager = BinanceWebSocketApiManager(
    disable_colorama=True
)

while True:
    print('~~~')
    print(random.choice(range(10)), flush=True)
    time.sleep(0.1)

@melonamin
Copy link
Contributor

Ha, that’s cool! Thank you for letting me know

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants