matryer / xbar

Put the output from any script or program into your macOS Menu Bar (the BitBar reboot)
https://xbarapp.com
MIT License
17.49k stars 643 forks source link

Crashing after a large number of refreshes #714

Open adamkdean opened 3 years ago

adamkdean commented 3 years ago

I don't know the specific number, but I've noticed that xbar is often crashing after a large number of refreshes.

I use a single script ran every second to report system vitals, including a request to an IP service I run, and a ping. At some point every few days, I notice the IP has changed as I'm changing networks, and that the other figures are also frozen.

Has anyone else experienced this? To fix it, I quit xbar and restart it.

matryer commented 3 years ago

@adamkdean hmm, sounds like something's wrong. Can you share the plugin that's causing this?

ehershey commented 3 years ago

I've been noticing this too. All my info in the menubar and menus stops updating. After it happens, clicking menu items under any plugins stops doing anything, refresh and refresh all stop doing anything, and I have to quit/restart. I have a bunch of plugins so I'm not sure which could be causing it. @matryer any tips to try to narrow it down? Maybe I could run a debug build or something if it would help and dump state when the problem occurs.

adamkdean commented 3 years ago

@matryer sorry for the delay, here's the script that I use, stats.1s.sh. I cobbled it together back when BitBar came out, and it worked fine for years until I upgraded. If you need anything else, let me know. Thanks.

#!/usr/bin/env bash

#
# Functions
#
function get_ifstat {
  interface=$1
  # 1 sample for 0.5 second interval
  # outputs two values (in/out) in kilobits per second
  /usr/local/bin/ifstat -n -w -i "${interface}" -b 0.5 1 | tail -n 1
}

function kilo_to_mega {
  printf "%0.2f\n" "$(bc -q <<< scale=2\;"${1}"/1000)"
}

function bits_to_bytes {
  printf "%0.2f\n" "$(bc -q <<< scale=2\;"${1}"/8)"
}

function print_ifstat {
  kbits_in=$(echo "$1" | awk '{ print $1 }')
  kbits_out=$(echo "$1" | awk '{ print $2 }')
  rxv=$kbits_in
  rxs="KB/s"
  txv=$kbits_out
  txs="KB/s"

  if [[ $(echo "$kbits_in > 1000" | bc -l) -eq 0 ]]; then
    kbs_in=$(bits_to_bytes "$kbits_in")
    rxv=$kbs_in
    rxs="KB/s"
  else
    mbits_in=$(kilo_to_mega "$kbits_in")
    mbs_in=$(bits_to_bytes "$mbits_in")
    rxv=$mbs_in
    rxs="MB/s"
  fi

  if [[ $(echo "$kbits_out > 1000" | bc -l) -eq 0 ]]; then
    kbs_out=$(bits_to_bytes "$kbits_out")
    txv=$kbs_out
    txs="KB/s"
  else
    mbits_out=$(kilo_to_mega "$kbits_out")
    mbs_out=$(bits_to_bytes "$mbits_out")
    txv=$mbs_out
    txs="MB/s"
  fi

  echo "RX: $rxv $rxs TX: $txv $txs"
}

function TWODP {
  printf "%0.2f\n" "$(bc -q <<< scale=2\;"${1}")"
}

#
# Get stats
#
INTERFACE="en1"
HOST="1.1.1.1"
LATENCY="? MS"
LATENCY=$(ping -c 1 $HOST | awk '/64 bytes from/ { print $7 }' | cut -d "=" -f2)
LATENCY=$(TWODP $LATENCY)
TRAFFIC=$(print_ifstat "$(get_ifstat ${INTERFACE})")
IP=$(curl -s -4 https://ip.adamkdean.co.uk)

CPU_NCPU=$(sysctl -n hw.logicalcpu)
CPU_TOTAL=$(ps -Ao %cpu= | paste -sd+ - | bc)
CPU_USAGE=$(echo "scale = 2; $CPU_TOTAL / $CPU_NCPU" | bc)
CPU_LOADAVG=$(sysctl -n vm.loadavg | cut -d " " -f2-4)

MEM_PAGES_WIRED=$(vm_stat | grep "Pages wired down:" | awk '{print $4}')
MEM_WIRED=$(echo "($MEM_PAGES_WIRED*4096)/1024/1024" | bc)
MEM_PAGES_ACTIVE=$(vm_stat | grep "Pages active:" | awk '{print $3}')
MEM_ACTIVE=$(echo "($MEM_PAGES_ACTIVE*4096)/1024/1024" | bc)
MEM_USED=$(echo "$MEM_WIRED+$MEM_ACTIVE" | bc)

#
# Output
#
printf "CPU: %0.1f%% (%s)    MEM: %s MB    %s    LATENCY: %s MS    IPV4: %s" \
  "$CPU_USAGE" "$CPU_LOADAVG" "$MEM_USED" "$TRAFFIC" "$LATENCY" "$IP"
tthkbw commented 3 years ago

I, too, have begun to see this issue. I have three home grown scripts I run with bar. one weather script refreshes every 3 minutes and locks up after a few days. It is the most noticeable one to fail as the others refresh more infrequently or don't obviously show that they have failed.

to fix it requires stopping and restarting xbar.

Here's the code for the weather script:

#!/usr/bin/env bash

print_weather_icon() {
    case $1 in
        13*) echo -n 🌨 ;;
        20*) echo -n β›ˆ  ;;
        21*) echo -n 🌩 ;;
        22*) echo -n 🌩 ;;
        23*) echo -n β›ˆ  ;;
        50*) echo -n 🌧 ;;
        511) echo -n 🌧 ;;
        520) echo -n 🌧 ;;
        521) echo -n 🌧 ;;
        522) echo -n 🌧 ;;
        531) echo -n 🌧 ;;
        60*) echo -n ❄️ ;;
        61*) echo -n 🌨 ;;
        62*) echo -n ❄️ ;;
        701) echo -n 🌫 ;;
        711) echo -n 🌫 ;;
        721) echo -n 🌫 ;;
        731) echo -n 🌫 ;;
        741) echo -n 🌫 ;;
        751) echo -n 🌫 ;;
        761) echo -n 🌫 ;;
        771) echo -n 🌫 ;;
        781) echo -n πŸŒͺ ;;
        800) echo -n β˜€οΈ  ;;
        801) echo -n 🌀 ;;
        802) echo -n ⛅️ ;;
        803) echo -n ☁️ ;;
        804) echo -n ☁️ ;;
        *) echo -n "?" ;;
    esac
}

print_temperature() {
    temperature=$1
    echo -n "$temperatureΒ°F"
}

WEATHER_DATA=$(curl -s https://api.openweathermap.org/data/2.5/onecall?lat\=45.55\&lon\=\-122.83\&exclude\=minutely,hourly\&units\=imperial\&appid=)

# echo $WEATHER_DATA

NOW_TEMP=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r '.current.temp')
declare -i icon
icon=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r '.current.weather[0].id')
echo "$(print_weather_icon $icon) $NOW_TEMP"

echo "---"
DAY1=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[1].sunrise')
DAY1DATEXX="$(date -r $DAY1 '+%a, %b %d')"
DAY2=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[2].sunrise')
DAY2DATEXX="$(date -r $DAY2 '+%a, %b %d')"
DAY3=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[3].sunrise')
DAY3DATEXX="$(date -r $DAY3 '+%a, %b %d')"
DAY4=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[4].sunrise')
DAY4DATEXX="$(date -r $DAY4 '+%a, %b %d')"
DAY5=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[5].sunrise')
DAY5DATEXX="$(date -r $DAY5 '+%a, %b %d')"
DAY6=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[6].sunrise')
DAY6DATEXX="$(date -r $DAY6 '+%a, %b %d')"
DAY7=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[7].sunrise')
DAY7DATEXX="$(date -r $DAY7 '+%a, %b %d')"

DAY0MAX=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[0].temp.max' | sed '{s/[.].*$//;}')
DAY1MAX=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[1].temp.max' | sed '{s/[.].*$//;}')
DAY2MAX=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[2].temp.max' | sed '{s/[.].*$//;}')
DAY3MAX=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[3].temp.max' | sed '{s/[.].*$//;}')
DAY4MAX=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[4].temp.max' | sed '{s/[.].*$//;}')
DAY5MAX=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[5].temp.max' | sed '{s/[.].*$//;}')
DAY6MAX=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[6].temp.max' | sed '{s/[.].*$//;}')
DAY7MAX=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[7].temp.max' | sed '{s/[.].*$//;}')
DAY0MIN=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[0].temp.min' | sed '{s/[.].*$//;}')
DAY1MIN=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[1].temp.min' | sed '{s/[.].*$//;}')
DAY2MIN=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[2].temp.min' | sed '{s/[.].*$//;}')
DAY3MIN=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[3].temp.min' | sed '{s/[.].*$//;}')
DAY4MIN=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[4].temp.min' | sed '{s/[.].*$//;}')
DAY5MIN=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[5].temp.min' | sed '{s/[.].*$//;}')
DAY6MIN=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[6].temp.min' | sed '{s/[.].*$//;}')
DAY7MIN=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[7].temp.min' | sed '{s/[.].*$//;}')
DAY0ICON=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[0].weather[0].id' | sed '{s/-day//;}')
DAY1ICON=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[1].weather[0].id' | sed '{s/-day//;}')
DAY2ICON=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[2].weather[0].id' | sed '{s/-day//;}')
DAY3ICON=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[3].weather[0].id' | sed '{s/-day//;}')
DAY4ICON=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[4].weather[0].id' | sed '{s/-day//;}')
DAY5ICON=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[5].weather[0].id' | sed '{s/-day//;}')
DAY6ICON=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[6].weather[0].id' | sed '{s/-day//;}')
DAY7ICON=$(echo "$WEATHER_DATA" | /usr/local/bin/jq -r .'daily[7].weather[0].id' | sed '{s/-day//;}')

echo "      Today:  $DAY0MAX/$DAY0MIN  - $(print_weather_icon $DAY0ICON) | color=#000000" | sed '{s/$/ font=Courier/;}'
echo "$DAY1DATEXX:  $DAY1MAX/$DAY1MIN  - $(print_weather_icon $DAY1ICON) | color=#000000" | sed '{s/$/ font=Courier/;}'
echo "$DAY2DATEXX:  $DAY2MAX/$DAY2MIN  - $(print_weather_icon $DAY2ICON) | color=#000000" | sed '{s/$/ font=Courier/;}'
echo "$DAY3DATEXX:  $DAY3MAX/$DAY3MIN  - $(print_weather_icon $DAY3ICON) | color=#000000" | sed '{s/$/ font=Courier/;}'
echo "$DAY4DATEXX:  $DAY4MAX/$DAY4MIN  - $(print_weather_icon $DAY4ICON) | color=#000000" | sed '{s/$/ font=Courier/;}'
echo "$DAY5DATEXX:  $DAY5MAX/$DAY5MIN  - $(print_weather_icon $DAY5ICON) | color=#000000" | sed '{s/$/ font=Courier/;}'
echo "$DAY6DATEXX:  $DAY6MAX/$DAY6MIN  - $(print_weather_icon $DAY6ICON) | color=#000000" | sed '{s/$/ font=Courier/;}'
echo "$DAY7DATEXX:  $DAY7MAX/$DAY7MIN  - $(print_weather_icon $DAY7ICON) | color=#000000" | sed '{s/$/ font=Courier/;}'
matryer commented 3 years ago

If you run xbar in terminal, you should see any output in the event of a crash.

~/Applications/xbar.app/Contents/MacOS/xbar

@leaanthony Perhaps you and I can pair on this at some point and see if we can recreate it?

leaanthony commented 3 years ago

Yeah cool. Let me know when you're free

tthkbw commented 3 years ago

I have been running xbar from the command line and have seen multiple failures where it hangs. These failures appear to be caused by local network failures in which local hosts that my xbar scripts access are not available. Still, perhaps these log messages would be useful to those who understand xbar.

The first failure shows an interesting 'feature' in the logging. For some reason, when a single script (of three active scripts) fails, the other two scripts show 'finished' instead of 'cycling' or 'refresh' at the time of failure. I'm not sure why this run failed, but I suspect it was because the pihole host was not accessible.

2021/05/15 20:08:58 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/15 20:08:58 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/15 20:08:59 battery.1h.py: cycling: battery.1h.py 2021/05/15 20:09:03 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/15 20:09:03 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/15 20:09:04 battery.1h.py: cycling: battery.1h.py 2021/05/15 20:09:08 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/15 20:09:08 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/15 20:09:09 battery.1h.py: cycling: battery.1h.py 2021/05/15 20:09:13 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/15 20:09:13 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/15 20:09:14 battery.1h.py: cycling: battery.1h.py 2021/05/15 20:09:18 pihole.30s.sh: refreshing: pihole.30s.sh 2021/05/15 20:09:18 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/15 20:09:18 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/15 20:09:19 battery.1h.py: cycling: battery.1h.py 2021/05/15 20:09:23 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/15 20:09:23 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/15 20:09:24 battery.1h.py: cycling: battery.1h.py 2021/05/15 20:09:27 openweather.3m.sh: finished 2021/05/15 20:09:27 battery.1h.py: finished 2021/05/15 20:09:43 pihole.30s.sh: ERR: signal: killed

The next run I captured the startup:

m1mini--/Users/tbrown➜ /Applications/xbar.app/Contents/MacOS/xbar xbar v2.0.42-beta 2021/05/15 21:40:53 battery.1h.py: cycling: battery.1h.py 2021/05/15 21:40:54 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/15 21:40:57 checking for updates... (current: v2.0.42-beta) 2021/05/15 21:40:57 updates: passive true 2021/05/15 21:40:57 updates: AutoUpdate true 2021/05/15 21:40:57 update: you have the latest version 2021/05/15 21:40:58 battery.1h.py: cycling: battery.1h.py 2021/05/15 21:40:59 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/15 21:41:03 battery.1h.py: cycling: battery.1h.py 2021/05/15 21:41:04 openweather.3m.sh: cycling: openweather.3m.sh

This run failed when the url access to the pihole failed:

2021/05/16 05:37:57 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/16 05:38:00 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/16 05:38:01 battery.1h.py: cycling: battery.1h.py 2021/05/16 05:38:02 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/16 05:38:03 battery.1h.py: finished 2021/05/16 05:38:03 openweather.3m.sh: finished Traceback (most recent call last): File "/Users/tbrown/bin/pistats.py", line 26, in print(str(summary['ads_percentage_today']) + '% Blocked') KeyError: 'ads_percentage_today' 2021/05/16 05:58:46 pihole.30s.sh: ERR: signal: killed: Traceback (most recent call last): pihole.30s.sh: File "/Users/tbrown/bin/pistats.py", line 26, in pihole.30s.sh: print(str(summary['ads_percentage_today']) + '% Blocked') pihole.30s.sh: KeyError: 'ads_percentage_today' pihole.30s.sh:

At this point, I think my failures are caused by my own internal network failures. There were name resolution issues which I fixed. Then a host failure caused the failure of pinhole.30s.sh.

However, for some reason, Xbar hangs as a result of the network failure in a script. Seems like Xbar shouldn't care about this and should keep attempting to run scripts even if they fail. It is probably important that Xbar reports 'finished' on the other two scripts run at the time the third script failed. What does this mean?

matryer commented 3 years ago

Thanks @tthkbw this is great.

adamkdean commented 3 years ago

For what it's worth, I am often changing networks, various VPNs. That's how I notice it hasn't updated, when the IP is wrong in xbar.

matryer commented 3 years ago

This is a good lead. We’ll see if network issues do in fact cause xbar to hang somewhere.

tthkbw commented 3 years ago

Here is a log from my latest failure. I'm not sure what happened here. As far as I can tell, the network did not fail. The message "(23) Failed writing body" is a new one:

2021/05/20 20:13:30 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/20 20:13:33 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/20 20:13:34 battery.1h.py: cycling: battery.1h.py 2021/05/20 20:13:35 pihole.30s.sh: refreshing: pihole.30s.sh 2021/05/20 20:13:35 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/20 20:13:38 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/20 20:13:40 battery.1h.py: cycling: battery.1h.py 2021/05/20 20:13:41 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/20 20:13:43 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/20 20:13:45 battery.1h.py: cycling: battery.1h.py 2021/05/20 20:13:46 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/20 20:13:48 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/20 20:13:50 battery.1h.py: cycling: battery.1h.py 2021/05/20 20:13:51 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/20 20:13:53 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/20 20:13:55 battery.1h.py: cycling: battery.1h.py 2021/05/20 20:13:56 pihole.30s.sh: cycling: pihole.30s.sh 2021/05/20 20:13:57 openweather.3m.sh: refreshing: openweather.3m.sh 2021/05/20 20:13:58 openweather.3m.sh: cycling: openweather.3m.sh 2021/05/20 20:13:58 pihole.30s.sh: finished 2021/05/20 20:13:58 battery.1h.py: finished (23) Failed writing body 2021/05/20 20:13:58 openweather.3m.sh: ERR: signal: killed: (23) Failed writing body openweather.3m.sh: 2021/05/20 21:55:20 checking for updates... (current: v2.0.42-beta) 2021/05/20 21:55:20 updates: passive true 2021/05/20 21:55:20 updates: AutoUpdate true 2021/05/20 21:55:20 update: you have the latest version

This ran for a couple of days, although I was playing with the pihole.30.sh script during that time. Interesting that it looks like xbar restarted more that an hour and a half after the failure, but it was not updating any scripts after that.

I have lots of time to play around with this, so if folks have suggestions for me to try to assist in debug, let me know. For now, I am going to test with a script that updates rapidly (like every second), prints the time in the menubar (so I can easily tell if it fails), and pings local machines on my network.

tthkbw commented 3 years ago

Here is the latest failure:

2021/05/22 05:33:48 openweather.3m.sh: cycling: openweather.3m.sh
2021/05/22 05:33:50 battery.1h.py: cycling: battery.1h.py
2021/05/22 05:33:50 pihole.10s.sh: refreshing: pihole.10s.sh
2021/05/22 05:33:50 pihole.10s.sh: cycling: pihole.10s.sh
2021/05/22 05:33:52 clock.5s.sh: finished
2021/05/22 05:33:52 openweather.3m.sh: finished
2021/05/22 05:33:52 battery.1h.py: finished
2021/05/22 05:33:52 pihole.10s.sh: ERR: signal: killed

clock.5s.sh ran the command 'date', then pinged three local machines.

pinhole.10s.sh used sshpass to grab statistics from my pinhole server (a raspberry pi adblocker) and display them.

This run lasted nearly 24 hours before failing.

Based on what I have seen so far, I am suspicious that xbar doesn't like it if processes it runs take to long? Maybe only network processes? I going to futz around with this some more and see if I can prove that.

gimbo commented 3 years ago

@tthkbw wrote:

Based on what I have seen so far, I am suspicious that xbar doesn't like it if processes it runs take to long?

Looking at https://github.com/matryer/xbar/issues/704, it seems there's currently a hard-coded time limit of one minute; I'm not a Go person so I'm not the one to look at the code around that and see if it's implicated, but I wonder if this is somehow involved.

I'm experiencing this issue too, so I'm going to try to ensure all that of my plugins which perform potentially long operations (in particular network operations) have timeouts on those operations, and see if that helps. πŸ€·πŸ»β€β™‚οΈ Might be a red herring, of course.

gimbo commented 3 years ago

I haven't done that yet, but I did write a script that kills/relaunches xbar when I notice it's stuck β€” in case that's of use to anyone else.

gimbo commented 3 years ago

I think I've disproven my timeout hypothesis...

Here's a plugin which just reads and displays three random hex digits from dev/random:

#!/bin/bash
# <xbar.title>Rando Calrissian</xbar.title>
# <xbar.version>v1.0</xbar.version>
# <xbar.author>Andy Gimblett</xbar.author>
# <xbar.author.github>gimbo</xbar.author.github>
# <xbar.desc>Just randomly show a 3 printable characters; for investigating issue #714</xbar.desc>

# Via https://gist.github.com/princebot/0c7ecb7410509744006bd94b3756edeb
LC_CTYPE=C tr -d -c '[:xdigit:]' </dev/urandom | head -c 3

echo "| color=gray | font='Fira Mono' | size=11"

I've had it running every 5 seconds since Friday (barring laptop downtime, and with a couple of reboots along the way), and I've just noticed that it stopped updating some time today. Refresh / Refresh All have no effect, but xbar's UI seems to be completely responsive otherwise.

AFAICS there's no way this plugin should ever crash or time out itself... Seems pretty safe?

So I think that whatever's crashing, it's independent of the specific plugins used/their timing issues, etc.

... and that's probably about the limit of my ability to debug this problem. Back to the experts!

alexthehurst commented 3 years ago

I'm seeing this, too, with xbar v2.0.42-beta. It runs well for a while and then stops updating and doesn't respond to "Refresh," "Refresh All," or any of the menu actions. It runs for at least a day or so, but I haven't noted this duration carefully. I just found the debugging advice in this thread, and I'll log the next run. I have a 1s plugin and a 5s plugin, and a plugins/disabled folder with an old BitBar plugin.

Here are the contents of my plugins folder:

pomodoro.1s.sh

#!/bin/bash
#
# <bitbar.title>Pomodoro Timer</bitbar.title>
# <bitbar.version>v1.0</bitbar.version>
# <bitbar.author>Goran Gajic</bitbar.author>
# <bitbar.author.github>gorangajic</bitbar.author.github>
# <bitbar.desc>Pomodoro Timer that uses Pomodoro Techniqueβ„’</bitbar.desc>
# <bitbar.image>http://i.imgur.com/T0zFY89.png</bitbar.image>

WORK_TIME=25
BREAK_TIME=3

SAVE_LOCATION=$TMPDIR/bitbar-promodo
TOMATO='πŸ…'

WORK_TIME_IN_SECONDS=$((WORK_TIME * 60))
BREAK_TIME_IN_SECONDS=$((BREAK_TIME * 60))

CURRENT_TIME=$(date +%s)

if [ -f "$SAVE_LOCATION" ];
then
    DATA=$(cat "$SAVE_LOCATION")

else
    DATA="$CURRENT_TIME|0"
fi

TIME=$(echo "$DATA" | cut -d "|" -f1)
STATUS=$(echo "$DATA" | cut -d "|" -f2)

function changeStatus {
    echo "$CURRENT_TIME|$1" > "$SAVE_LOCATION";
    osascript -e "display notification \"$2\" with title \"$TOMATO Pomodoro\" sound name \"$3\"" &> /dev/null
}

function breakMode {
    changeStatus "2" "Break Mode" "Glass"
}

function workMode {
    changeStatus "1" "Work Mode" "Blow"
}

case "$1" in
"work")
    workMode
    exit
  ;;
"break")
    breakMode
    exit
  ;;
"disable")
    changeStatus "0" "Disabled"
    exit
  ;;
esac

function timeLeft {
    local FROM=$1
    local TIME_DIFF=$((CURRENT_TIME - TIME))
    local TIME_LEFT=$((FROM - TIME_DIFF))
    echo "$TIME_LEFT";
}

function getSeconds {
    echo $(($1 % 60))
}

function getMinutes {
    echo $(($1 / 60))
}

function printTime {
    SECONDS=$(getSeconds "$1")
    MINUTES=$(getMinutes "$1")
    printf "%s %02d:%02d| color=%s\n" "$TOMATO" "$MINUTES" "$SECONDS"  "$2"
}

case "$STATUS" in
# STOP MODE
"0")
    echo "$TOMATO"
  ;;
"1")
    TIME_LEFT=$(timeLeft $WORK_TIME_IN_SECONDS)
    if (( "$TIME_LEFT" < 0 )); then
        breakMode
    fi
    printTime "$TIME_LEFT" "red"
  ;;
"2")
    TIME_LEFT=$(timeLeft $BREAK_TIME_IN_SECONDS)
    if (("$TIME_LEFT" < 0)); then
        workMode
    fi
    printTime "$TIME_LEFT" "green"
  ;;
esac

echo "---";
echo "πŸ‘” Work | bash=\"$0\" param1=work terminal=false"
echo "β˜• Break | bash=\"$0\" param1=break terminal=false"
echo "πŸ”Œ Disable | bash=\"$0\" param1=disable terminal=false"

time.5s.sh

#!/bin/bash

# Utility: https://xbarapp.com/docs/plugins/Dev/totp.20s.sh.html
if [[ "$1" == "copy" ]]; then
  echo -n "$(echo -n "$2")" | pbcopy
  exit
fi

# setup
myUuid=$(uuidgen | tr '[:upper:]' '[:lower:]' | tr -d '\n')
zeroUuid='00000000-0000-0000-0000-000000000000'
shortDate=$(date -u +"%Y-%m-%dT%H:%MZ")
fullDate=$(date -u +"%Y-%m-%dT%H:%M:%SZ")
migrationTemplate=$(date -u +"%Y%m%d%H%M%S-newmigration.js")

# output
echo "$shortDate"
echo '---'
echo $(date -u +"Sprint %Y-%U") "| href=https://app.asana.com/0/home/[redacted]"
echo "$myUuid | bash='$0' param1=copy param2='$myUuid' terminal=false"
echo "$zeroUuid | bash='$0' param1=copy param2='$zeroUuid' terminal=false | alternate=true"
echo "$fullDate | bash='$0' param1=copy param2='$fullDate' terminal=false"
echo "$migrationTemplate | bash='$0' param1=copy param2='$migrationTemplate' terminal=false | alternate=true"
alexthehurst commented 3 years ago

Update: it crashed overnight. Here are the logs:

2021/06/30 05:30:47 time.5s.sh: refreshing: time.5s.sh
2021/06/30 05:30:47 time.5s.sh: cycling: time.5s.sh
2021/06/30 05:30:48 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:49 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:50 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:51 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:52 time.5s.sh: cycling: time.5s.sh
2021/06/30 05:30:52 time.5s.sh: refreshing: time.5s.sh
2021/06/30 05:30:53 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:54 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:55 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:56 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:57 time.5s.sh: cycling: time.5s.sh
2021/06/30 05:30:57 time.5s.sh: refreshing: time.5s.sh
2021/06/30 05:30:57 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/06/30 05:30:58 time.5s.sh: ERR: signal: killed
2021/06/30 09:55:58 checking for updates... (current: v2.0.42-beta)
2021/06/30 09:55:58 updates: passive true
2021/06/30 09:55:58 updates: AutoUpdate false
2021/06/30 09:55:58 update: you have the latest version

Here's how I invoked it: $ /Applications/xbar.app/Contents/MacOS/xbar | tee -a ~/xbar-$( date -u +"%Y-%m-%dT%H:%M:%SZ").log

I don't have the top of the log, just the recent scrollback, because it looks like the relaunch wiped the file (last modified 09:55 with no contents).

It looks like the update check at 09:55 PDT was almost exactly 24 hours after I launched it (2021-06-29T16:55:46Z), so some part of xbar was still running and doing scheduled update checks, it seems?

In case we're trying to count iterations: the crash was about 70512 seconds after the launch, so 70512 runs of pomodoro and 14102 runs of time.

leaanthony commented 3 years ago

Potentially fixed by #736

adamkdean commented 3 years ago

Was #736 included in v2.1.0-beta? If so, the issue persists I'm afraid.

leaanthony commented 3 years ago

It was only a potential as I didn't know if your issue was memory related or not.

adamkdean commented 3 years ago

@leaanthony no worries, just reporting my experience after updating a few days ago. πŸ™‚

leaanthony commented 3 years ago

I'll try running your 2 plugins in debug mode and see where we get

alexthehurst commented 3 years ago

I upgraded to 2.1.0-beta last night, and notice the same crash has happened again on the new version.

On Jul 5, 2021, at 6:05 AM, Lea Anthony @.***> wrote:

I'll try running your 2 plugins in debug mode and see where we get

β€” You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/matryer/xbar/issues/714#issuecomment-874097236, or unsubscribe https://github.com/notifications/unsubscribe-auth/AB22GZ5CCCKYH7SZ4PYGWFLTWGUY5ANCNFSM43ZVIQJA.

tthkbw commented 3 years ago

I, too, can verify that the 2.1.0 beta does not change this bug. I have built a monitoring system that verifies xbar is updating on a scheduled basis and restarts it if it hangs. With my xbar scripts, xbar works for about two days and then crashes and is restarted. I don't think this has changed at all with 2.1.0.

I don't have any insight as to what causes the crash. I have moved scripts that use the network and have a propensity for failure or taking a lot of time out of xbar (I have those scripts running from plist files and creating local text files that xbar scripts monitor), and have played with update frequencies without getting any useful information.

alexthehurst commented 3 years ago

Still seeing this crash under v2.1.4-beta. Running with logging now with a single, very minimal plugin enabled. This reoccurs for me around once every day or two.

matryer commented 3 years ago

@alexthehurst thank you, let me know if you find any clues

leaanthony commented 3 years ago

@alexthehurst - Is what you are seeing most likely related to known issues with actually executing a script, eg network issues, laptop goes to sleep, etc, or does it feel more like a system error, eg memory runs out?

alexthehurst commented 3 years ago

Hard to say. I've seen this happen while running a plug-in which doesn't do much (time.sh upthread), but I'm running a test now with a stripped down plug-in that does almost nothing at all and I'll update with the result. I can't rule out system issues, but I haven't made a connection with anything specific.

adamkdean commented 3 years ago

For what it’s worth: I ran a test with three scripts, one that does quite a bit (shared above) and two that simply incremented a number in a file, one every second and one every two seconds. All three scripts crashed at the same time, once after 30,000 seconds, and the next about about 250,000 seconds.

I can’t say for sure whether the machine sleeping caused this though. It’s a hard thing to notice.

On Tue, 10 Aug 2021 at 21:52, Alex Hurst @.***> wrote:

Hard to say. I've seen this happen while running a plug-in which doesn't do much (time.sh upthread), but I'm running a test now with a stripped down plug-in that does almost nothing at all and I'll update with the result. I can't rule out system issues, but I haven't made a connection with anything specific.

β€” You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/matryer/xbar/issues/714#issuecomment-896308595, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAMQIZZBTS23NQOQ4YUEN23T4GGQLANCNFSM43ZVIQJA . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&utm_campaign=notification-email .

gimbo commented 3 years ago

@leaanthony:

Is what you are seeing most likely related to known issues with actually executing a script, eg network issues, laptop goes to sleep, etc, or does it feel more like a system error, eg memory runs out?

I know that question wasn't directed at me, but did you see this comment? Just generating random numbers is sufficient to trigger this behaviour. (For clarity: when I ran those tests this was the only plugin running.)

leaanthony commented 3 years ago

@gimbo thanks

adamkdean commented 3 years ago

@gimbo I'm not entirely convinced the scripts are the issue. Even simple scripts incrementing a number in a file crash, and when they do, all xbar scripts crash. We've had a lot of reports of xbar crashing, but have there been any instances where it doesn't crash ever?

leaanthony commented 3 years ago

I'll carve out a couple of hours over the weekend for this. It would help if there was a way to quickly make it crash as the last time I looked at this I ran my "acid test" script for a whole weekend and it didn't fall over. Suggestions?

adamkdean commented 3 years ago

Nothing I've tried has made it crash more frequently, however, I wonder if you were to change the execution interval from 1s to say 10ms etc, if you could then drastically reduce the time to crash?

alexthehurst commented 3 years ago

@alexthehurst thank you, let me know if you find any clues

I ran this test with a minimal script for 8 days straight and didn't encounter the crash. Starting another run with the full set of scripts to see what we see.

leaanthony commented 3 years ago

What would be really useful is to run it from the CLI via the .app package and capture the terminal output. I'm keen to get some visibility on the crash.

alexthehurst commented 3 years ago

What would be really useful is to run it from the CLI via the .app package and capture the terminal output. I'm keen to get some visibility on the crash.

Yep! That's the approach I'm taking. On an earlier run, it got me the output that you've seen upthread:

2021/07/03 20:31:27 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/07/03 20:31:28 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/07/03 20:31:29 time.5s.sh: cycling: time.5s.sh
2021/07/03 20:31:29 time.5s.sh: refreshing: time.5s.sh
2021/07/03 20:31:30 pomodoro.1s.sh: refreshing: pomodoro.1s.sh
2021/07/03 20:31:30 time.5s.sh: finished
2021/07/03 20:31:30 pomodoro.1s.sh: ERR: signal: killed
2021/07/03 22:44:59 checking for updates... (current: v2.0.42-beta)
2021/07/03 22:44:59 updates: passive true
2021/07/03 22:44:59 updates: AutoUpdate false

Not sure what I'm seeking this time aside from reproducibility. What does scriptname: finished mean? It seems to happen every 12 hours, like so (this log from a test that did not crash):

2021/08/13 06:03:03 time.5s.sh: refreshing: time.5s.sh
2021/08/13 06:03:08 time.5s.sh: cycling: time.5s.sh
2021/08/13 06:03:08 time.5s.sh: refreshing: time.5s.sh
2021/08/13 06:03:11 time.5s.sh: finished
2021/08/13 06:03:16 time.5s.sh: cycling: time.5s.sh
2021/08/13 06:03:16 time.5s.sh: refreshing: time.5s.sh
2021/08/13 06:03:21 time.5s.sh: cycling: time.5s.sh

Something that may be a complete red herring: throughout the summer I've been regularly experiencing thermal CPU throttling on my Intel MacBook Pro because I'm in a hot room. A couple of weeks ago we got the AC fixed, and I haven't seen the overheating since, which roughly corresponds to the timespan of that last minimal test that didn't crash. I didn't notice one way or another whether the crashes actually coincided with the throttling, unfortunately.

adamkdean commented 3 years ago

Just on the overheating part, I've been running this on an iMac Pro with adequate cooling, often running quite under-utilised, and still getting crashes every day or two. I do put the machine to sleep a lot though.

alexthehurst commented 3 years ago

New crash today. Log is attached. At the top of the log, I include the source of all the plugins which were enabled. One (time.sh) is custom, and the others are installed through the xbar plugin browser. Circumstance: after idling the computer overnight, I used it for about an hour, then got up for a coffee break and returned. The crash happened around the time I left the computer and came back to it (sorry I can't be more precise). Nothing of note in the system logs.

Most relevant part, like we've seen before: at some point everything says "finished" while one script says "killed", then there are no more script runs, but the autoupdater continues on schedule.

2021/08/20 06:08:45 mtop.5s.sh: cycling: 001-mtop.5s.sh
2021/08/20 06:08:45 cpu-thermal-throttle.30s.sh: refreshing: 001-cpu-thermal-throttle.30s.sh
2021/08/20 06:08:45 cpu-thermal-throttle.30s.sh: cycling: 001-cpu-thermal-throttle.30s.sh
2021/08/20 06:08:46 clipboard-history.3s.sh: refreshing: 001-clipboard-history.3s.sh
2021/08/20 06:08:48 time.5s.sh: cycling: time.5s.sh
2021/08/20 06:08:48 time.5s.sh: refreshing: time.5s.sh
2021/08/20 06:08:49 time.5s.sh: finished
2021/08/20 06:08:49 clipboard-history.3s.sh: finished
2021/08/20 06:08:49 cpu-thermal-throttle.30s.sh: finished
2021/08/20 06:08:49 mtop.5s.sh: ERR: signal: killed
2021/08/20 09:11:53 checking for updates... (current: v2.1.4-beta)
2021/08/20 09:11:53 updates: passive true
2021/08/20 09:11:53 updates: AutoUpdate false
2021/08/20 09:11:54 update: you have the latest version

2021-08-18-xbar-log.gz

leaanthony commented 3 years ago

Thanks for this. Did the computer go to sleep during that time?

elia commented 2 years ago

I've been noticing this too. All my info in the menubar and menus stops updating. After it happens, clicking menu items under any plugins stops doing anything, refresh and refresh all stop doing anything, and I have to quit/restart. I have a bunch of plugins so I'm not sure which could be causing it. @matryer any tips to try to narrow it down? Maybe I could run a debug build or something if it would help and dump state when the problem occurs.

https://github.com/matryer/xbar/issues/714#issuecomment-831968574

@leaanthony I have this same issue, usually in the morning after the Mac has been sleeping through the night, I have a process sample taken with Activity Monitor while xbar was behaving in that way if it's of any use

leaanthony commented 2 years ago

Please upload πŸ‘

elia commented 2 years ago

@leaanthony there https://gist.github.com/elia/365e64e392b7d707424ba18400645906

leaanthony commented 2 years ago

Thanks. I suspect it's in relation to http timeouts and goroutines. Searching for anything around "laptop sleep goroutines" returns mainly false positives πŸ˜”

elia commented 2 years ago

Tonight I left xbar running from the terminal to catch logs, here they are with some cleanup/scraping, my comments are in ALL CAPS:

[HERE THE LID IS OPEN AND THE MAC NOT SLEEPING]
2021/11/18 22:27:49 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 22:27:50 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/18 22:27:52 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 22:27:53 time-watch-other.15m.rb: refreshing: time-watch-other.15m.rb
2021/11/18 22:27:54 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 22:27:54 macos.10m.rb: refreshing: macos.10m.rb
2021/11/18 22:27:54 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 22:27:55 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/18 22:27:57 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 22:27:59 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 22:27:59 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 22:28:00 meetings.1m.rb: refreshing: meetings.1m.rb
2021/11/18 22:28:00 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/18 22:28:02 time-watch.15s.rb: refreshing: time-watch.15s.rb
2021/11/18 22:28:02 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 22:28:04 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 22:28:04 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 22:28:06 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/18 22:28:08 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 22:28:09 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 22:28:09 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 22:28:11 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/18 22:28:13 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 22:28:14 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 22:28:14 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 22:28:16 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/18 22:28:18 time-watch.15s.rb: refreshing: time-watch.15s.rb
2021/11/18 22:28:18 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 22:28:19 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 22:28:19 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 22:28:21 meetings.1m.rb: cycling: meetings.1m.rb
[THIS IS THE FIRST ONE-HOUR JUMP]
2021/11/18 23:39:39 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 23:39:39 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 23:39:40 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 23:39:42 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/18 23:39:44 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 23:39:44 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 23:39:45 macos.10m.rb: cycling: macos.10m.rb
2021/11/18 23:39:47 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/18 23:39:49 time-watch.15s.rb: refreshing: time-watch.15s.rb
2021/11/18 23:39:49 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/18 23:39:50 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/18 23:39:50 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 01:39:49 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 01:39:49 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 01:39:50 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 01:39:51 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 01:39:54 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 01:39:54 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 01:39:55 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 01:39:56 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 01:39:59 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 01:39:59 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 01:40:00 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 01:40:01 time-watch.15s.rb: refreshing: time-watch.15s.rb
2021/11/19 01:40:01 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 01:40:04 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 01:40:04 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 01:40:05 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 01:40:09 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 01:40:09 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 01:40:09 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 01:40:10 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 01:40:12 meetings.1m.rb: refreshing: meetings.1m.rb
2021/11/19 01:40:14 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 01:40:14 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 01:40:14 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 01:40:15 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 03:40:14 time-watch.15s.rb: refreshing: time-watch.15s.rb
2021/11/19 03:40:14 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 03:40:14 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 03:40:15 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 03:40:18 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 03:40:19 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 03:40:20 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 03:40:21 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 03:40:23 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 03:40:24 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 03:40:25 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 03:40:26 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 05:40:25 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 05:40:26 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 05:40:26 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 05:40:27 time-watch.15s.rb: refreshing: time-watch.15s.rb
2021/11/19 05:40:27 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 05:40:30 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 05:40:31 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 05:40:31 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 05:40:34 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 07:40:33 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 07:40:33 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 07:40:33 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 07:40:35 time-watch.15s.rb: cycling: time-watch.15s.rb
2021/11/19 07:40:38 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 07:40:38 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
2021/11/19 07:40:38 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 07:40:40 time-watch.15s.rb: refreshing: time-watch.15s.rb
2021/11/19 07:40:40 time-watch.15s.rb: cycling: time-watch.15s.rb
[MAC IS AWAKENED BY THE SCHEDULER, NO MORE 1-HOUR JUMPS]
2021/11/19 08:00:01 macos.10m.rb: cycling: macos.10m.rb
2021/11/19 08:00:01 meetings.1m.rb: cycling: meetings.1m.rb
2021/11/19 08:00:01 time-watch-other.15m.rb: cycling: time-watch-other.15m.rb
[RUBY ERROR OUTPUT]
2021/11/19 08:00:01 time-watch.15s.rb: ERR: exit status 1: [RUBY ERROR OUTPUT]
time-watch.15s.rb: [RUBY ERROR OUTPUT]
time-watch.15s.rb: [MORE LINES...]
time-watch.15s.rb: [RUBY ERROR OUTPUT]
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: finished
2021/11/19 08:00:03 time-watch-other.15m.rb: finished
2021/11/19 08:00:03 meetings.1m.rb: finished
2021/11/19 08:00:03 macos.10m.rb: finished
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.title: Time Watcher 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.version: v1.0 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.author: Elia Schito 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.author.github: elia 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.desc: Track the time you're in the office, especially a remote office. 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.dependencies: ruby 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.title: Time Watcher 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.version: v1.0 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.author: Elia Schito 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.author.github: elia 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.desc: Track the time you're in the office, especially a remote office. 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch.15s.rb: bitbar.dependencies: ruby 
2021/11/19 08:00:03 time-watch.15s.rb: βœ“
time-watch.15s.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.title: Time Watcher 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.version: v1.0 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.author: Elia Schito 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.author.github: elia 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.desc: Track the time you're in the office, especially a remote office. 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.dependencies: ruby 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.title: Time Watcher 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.version: v1.0 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.author: Elia Schito 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.author.github: elia 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.desc: Track the time you're in the office, especially a remote office. 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 time-watch-other.15m.rb: bitbar.dependencies: ruby 
2021/11/19 08:00:03 time-watch-other.15m.rb: βœ“
time-watch-other.15m.rb: 
2021/11/19 08:00:03 meetings.1m.rb: ERR: signal: killed
2021/11/19 08:00:03 time-watch-other.15m.rb: ERR: signal: killed
2021/11/19 08:00:03 macos.10m.rb: ERR: signal: killed
2021/11/19 08:00:03 time-watch.15s.rb: ERR: signal: killed
[AT THIS POINT ICONS ARE NOT VISIBLE BUT CAN STILL CLICK AND ACCESS THE MENU, CLICKING ON CHECK UPDATES WORKS THO, THE WEB UI FOR BROWSING PLUGINS WORKS TOO]
2021/11/19 10:32:50 checking for updates... (current: v2.1.7-beta)
2021/11/19 10:32:50 updates: passive false
2021/11/19 10:32:50 updates: AutoUpdate true
2021/11/19 10:32:50 update: you have the latest version
[AT THIS POINT CLICKING ON QUIT TRIGGERED THE MARBLE OF DEATH]

and here's the sample https://gist.github.com/elia/cc6dcddec74a035946524a78301503d8

image
adamkdean commented 2 years ago

Thanks. I suspect it's in relation to http timeouts and goroutines. Searching for anything around "laptop sleep goroutines" returns mainly false positives πŸ˜”

I'm not so sure that http requests factor into this, at least, in tests I've performed, there have been crashes with a simple bash script counter alone. At this point, I just know to quit and restart daily. I wish I could help more in debugging but not really sure where to start β€” MacOS isn't my area of expertise sadly!

Happy to run any tests that may help though.

gimbo commented 2 years ago

@leaanthony said:

Thanks. I suspect it's in relation to http timeouts and goroutines.

@adamkdean replied:

I'm not so sure that http requests factor into this

I second that, at least as far as plugins are concerned; e.g. see this comment. Also, I'm now only running plugins which access local files (no http), and I'm still getting crashes.

The core of xbar probably does some http work, so timeouts+goroutines could factor in there though?

I haven't tried running xbar without any plugins at all, which I suppose (if the problem occurs) would prove the problem is in core. I'm going to try that now; if I get to the point where (to quote @elia) "clicking on Quit triggered the marble of death" then we can pretty be sure (I guess!) that it's got nothing to do with running plugins.

gimbo commented 2 years ago

I haven't tried running xbar without any plugins at all, which I suppose (if the problem occurs) would prove the problem is in core. I'm going to try that now; if I get to the point where (to quote @elia) "clicking on Quit triggered the marble of death" then we can pretty be sure (I guess!) that it's got nothing to do with running plugins.

No crashes over the last week of doing this; AFAICS running xbar without plugins doesn't lead to these crashes. (But of course this is just indicative; I could be totally wrong about that.)

adamkdean commented 1 year ago

Is this still an ongoing issue? I've had to stop using this because of the crashes and honestly, my life is less without it :(

The linked SwiftBar issue sounds eerily familiar: https://github.com/swiftbar/SwiftBar/issues/319

leaanthony commented 1 year ago

Hey Adam πŸ‘‹ This is a priority for fixing and I'll be looking at it more earnestly next week. My initial debugging via Instruments showed no memory leaks but the memory going up very slowly.

There's a lot of spinning plates right now and we just need to get them in sync. There's some good things ahead πŸ‘