mu-editor / mu

A small, simple editor for beginner Python programmers. Written in Python and Qt5.
http://codewith.mu
GNU General Public License v3.0
1.4k stars 434 forks source link

New `check_only_running_once()` call failing on macOS 10.13.6; test fails also. #2375

Closed haikusw closed 1 year ago

haikusw commented 1 year ago

What were you trying to do?

build and run mu on macOS 10.13.6 using python 3.8.10

What steps did you take to trigger the issue?

// setup pyenv veritual environment & activate // set it to use python 3.8.10 (latest 3.8) // git clone https://github.com/mu-editor/mu.git // do dev setup pip install -e ".[dev]" etc.

make run fails

make test fails one test relating to check_only_running_once()

Checking out the head -1 commit results in running successfully every time and all tests passing.

What did you expect to happen?

run successfully, all tests pass

What actually happened?

make run

results in:

(venv) haikumintthin:mu tyler$ make run rm -rf build rm -rf dist rm -rf .coverage rm -rf .eggs rm -rf .egg-info rm -rf docs/_build rm -rf .pytest_cache rm -rf lib rm -rf .mp4 rm -rf .git/avatar/ rm -rf venv-pup find . ( -name '.py[co]' -o -name dropin.cache ) -delete find . ( -name '.bak' -o -name dropin.cache ) -delete find . ( -name '.tgz' -o -name dropin.cache ) -delete find . | grep -E "(pycache)" | xargs rm -rf rm -f ./mu/locale/messages.pot rm -f ./mu/wheels/*.zip python run.py make: *** [run] Error 2


make test results in:

...

======================================================================================== FAILURES ========================================================================================= _ test_only_running_once __

def check_only_running_once():
    """If the application is already running log the error and exit"""
    try:
        with _shared_memory:
          _shared_memory.acquire()

mu/app.py:316:


self = <mu.app.SharedMemoryMutex object at 0x10c4bbbe0>

def acquire(self):
    if self._shared_memory.attach():
        pid = struct.unpack("q", self._shared_memory.data()[:8])
      raise MutexError("MUTEX: Mu is already running with pid %d" % pid)

E mu.app.MutexError: MUTEX: Mu is already running with pid 72090

mu/app.py:291: MutexError

During handling of the above exception, another exception occurred:

def test_only_running_once():
    """
    If we are the first to acquire the application lock we should succeed
    """
  check_only_running_once()

tests/test_app.py:419:


def check_only_running_once():
    """If the application is already running log the error and exit"""
    try:
        with _shared_memory:
            _shared_memory.acquire()
    except MutexError as exc:
        [message] = exc.args
        logging.error(message)
      sys.exit(2)

E SystemExit: 2

mu/app.py:320: SystemExit ------------------------------------------------------------------------------------ Captured log call ------------------------------------------------------------------------------------ ERROR root:app.py:319 MUTEX: Mu is already running with pid 72090 ================================================================================= short test summary info ================================================================================= FAILED tests/test_app.py::test_only_running_once - SystemExit: 2 ======================================================================= 1 failed, 1116 passed, 20 skipped in 30.98s ======================================================================= make: *** [test] Error 1


Oddly, I can get it to run if I run it in the debugger. It fails but then appears to re-run itself (possibly some aspect of the debugger?).

(venv) haikumintthin:mu tyler$ python3 -m pdb run.py

/Users/tyler/Documents/Work/mu/run.py(2)() -> from mu.app import run (Pdb) c The program exited via sys.exit(). Exit status: 2 /Users/tyler/Documents/Work/mu/run.py(2)() -> from mu.app import run (Pdb) c QSharedMemory::lock: already locked

Screen Shot 2022-12-24 at 6 22 54 PM


Looking at the log, it appears that it's somehow getting the shared memory space from the previous successful run. Like it's not being cleaned up when the process exits and is somehow in a global namespace where it can be found again (?).

I'm going to restart my machine and try again to see what a definitely not in memory situation results in.

Operating System Version

No response

Mu Version

No response

Other Info

No response

Editor Log

mu.log

haikusw commented 1 year ago

Happens on second launch.

Tested by rebooting, running Terminal, and then in Terminal:

$ cd Documents/Work/mu $ pyenv activate venv $ make clean $ make run -> Success $ make run -> Error 2

full command terminal session:

haikumintthin:mu tyler$ pyenv activate venv pyenv-virtualenv: prompt changing will be removed from future release. configure `export PYENV_VIRTUALENV_DISABLE_PROMPT=1' to simulate the behavior. (venv) haikumintthin:mu tyler$ make clean rm -rf build rm -rf dist rm -rf .coverage rm -rf .eggs rm -rf .egg-info rm -rf docs/_build rm -rf .pytest_cache rm -rf lib rm -rf .mp4 rm -rf .git/avatar/ rm -rf venv-pup find . ( -name '.py[co]' -o -name dropin.cache ) -delete find . ( -name '.bak' -o -name dropin.cache ) -delete find . ( -name '.tgz' -o -name dropin.cache ) -delete find . | grep -E "(pycache)" | xargs rm -rf rm -f ./mu/locale/messages.pot rm -f ./mu/wheels/.zip (venv) haikumintthin:mu tyler$ make run rm -rf build rm -rf dist rm -rf .coverage rm -rf .eggs rm -rf .egg-info rm -rf docs/_build rm -rf .pytest_cache rm -rf lib rm -rf .mp4 rm -rf .git/avatar/ rm -rf venv-pup find . ( -name '.py[co]' -o -name dropin.cache ) -delete find . ( -name '.bak' -o -name dropin.cache ) -delete find . ( -name '.tgz' -o -name dropin.cache ) -delete find . | grep -E "(pycache)" | xargs rm -rf rm -f ./mu/locale/messages.pot rm -f ./mu/wheels/.zip python run.py (venv) haikumintthin:mu tyler$ make run rm -rf build rm -rf dist rm -rf .coverage rm -rf .eggs rm -rf .egg-info rm -rf docs/_build rm -rf .pytest_cache rm -rf lib rm -rf .mp4 rm -rf .git/avatar/ rm -rf venv-pup find . ( -name '.py[co]' -o -name dropin.cache ) -delete find . ( -name '.bak' -o -name dropin.cache ) -delete find . ( -name '.tgz' -o -name dropin.cache ) -delete find . | grep -E "(pycache)" | xargs rm -rf rm -f ./mu/locale/messages.pot rm -f ./mu/wheels/*.zip python run.py make: *** [run] Error 2

mulog.txt

Guess the PR I was going to make for another issue is blocked until this is fixed or reverted and put on a development branch or whatever you folks normally do.

oh - I'm here:

(venv) haikumintthin:mu tyler$ git branch -vv * master 7987633 [origin/master] WIP: Prevent Mu from opening more than one instance (#2297)

haikusw commented 1 year ago

Addendum: All runs after the first one exit and show the PID of that first run. Here's the log with the first two runs (same as above), plus like three more I did to see if they always got that first run PID as the "currently running" process triggering an exit(2) (they did).

mulog_longer.txt

haikusw commented 1 year ago

Obviously extremely likely, but just to be doubly sure, tested checking out HEAD-1 and verified that it doesn't exhibit this issue:

(venv) haikumintthin:mu tyler$ git checkout HEAD@{1} Note: checking out 'HEAD@{1}'.

You are in 'detached HEAD' state. You can look around, make experimental changes and commit them, and you can discard any commits you make in this state without impacting any branches by performing another checkout.

If you want to create a new branch to retain commits you create, you may do so (now or later) by using -b with the checkout command again. Example:

git checkout -b

HEAD is now at 872dfa0 Merge pull request #2362 from mu-editor/appimage-docker (venv) haikumintthin:mu tyler$ make run rm -rf build rm -rf dist rm -rf .coverage rm -rf .eggs rm -rf .egg-info rm -rf docs/_build rm -rf .pytest_cache rm -rf lib rm -rf .mp4 rm -rf .git/avatar/ rm -rf venv-pup find . ( -name '.py[co]' -o -name dropin.cache ) -delete find . ( -name '.bak' -o -name dropin.cache ) -delete find . ( -name '.tgz' -o -name dropin.cache ) -delete find . | grep -E "(pycache)" | xargs rm -rf rm -f ./mu/locale/messages.pot rm -f ./mu/wheels/.zip python run.py (venv) haikumintthin:mu tyler$ make run rm -rf build rm -rf dist rm -rf .coverage rm -rf .eggs rm -rf .egg-info rm -rf docs/_build rm -rf .pytest_cache rm -rf lib rm -rf .mp4 rm -rf .git/avatar/ rm -rf venv-pup find . ( -name '.py[co]' -o -name dropin.cache ) -delete find . ( -name '.bak' -o -name dropin.cache ) -delete find . ( -name '.tgz' -o -name dropin.cache ) -delete find . | grep -E "(pycache)" | xargs rm -rf rm -f ./mu/locale/messages.pot rm -f ./mu/wheels/.zip python run.py

tjguk commented 1 year ago

Thank you very much for being so quick off the mark to test. I haven't looked in any detail yet at your logs, but I note your hypothesis: that the previous run's lock is still being held. I can definitely look into that possibility.

I'm somewhat surprised because I've tested this reasonably extensively on my (Windows) machine and all our GH test bots passed. It's not impossible that it's MacOS-specific (which will make it much harder for me to reproduce!) but there again at least one other of our dev team has tested successfully on Mac; and we have Macs in the GH test bots.

I'll leave the code in for now in the hope that I can rapidly "roll forward" by finding a robust way to ensure the lock is removed. But if I can't come up with something in short order, I'll roll back so as not to obstruct.

tjguk commented 1 year ago

Fixed by #2376 -- thanks very much @haikusw for both the error report and the fix