Strange Reinstall Issue

Development
1

I'm using OctoPrint 1.4.0 running on OctoPi 0.17.0 and Python 2.7. This all was recently installed (past few weeks).

I've been testing several upgrade paths for Octolapse v0.4.0, and have noticed something very odd within the plugin manger.

First, I'm using versioneer so that I can add tag and commit level info when installing from branches, releases, or during development. When installing from a release, commit info is not necessary and is omitted from the displayed version number. There is a link on the Octolapse tab embedded within the version, and if a user clicks on it it should either take them to the release notes, or to the most recent commit if they did not install from from a release. If they did not install from a release, there should be a short commit id after the version with a link to the commit. For example: v0.4.0rc3+u.dbe88db

When installing from a release, the version and link should look like this: v0.4.0rc3.

So, I had previously created a release (v0.4.0rc3), installed it in the plugin manager and the version displayed on the Octolapse tab was incorrect. I figured this was a bug in my code most likely, so I made some changes to the code (they were likely unnecessary), pushed them to the repo, deleted the old release and tag for v0.4.0rc3, and added another with the same name and tag name. After reinstalling this from the plugin manager, the commit level info was still there. It should have been v0.4.0rc3, not v0.4.0rc3+u.dbe88db, which was the commit version for the previous release I had just deleted.

I figured this was a caching issue, so I checked the _version.py file within the release assets, and sure enough the commit version there pointed to the proper release commit. I also navigated to the /home/pi/oprint/lib/python2.7/site-packages/octoprint_octolapse folder and checked _version.py there, and again it was correct. I then restarted the pi (full reboot) and tried a reinstall, but the same incorrect commit level info was there. I then uninstalled octolapse completely (cleaned all files) and tried again, and this time it got the right info. However, the plugin manager appears to have tried installing Octolapse twice:

Building wheels for collected packages: Octolapse
Building wheel for Octolapse (setup.py): started
Building wheel for Octolapse (setup.py): still running...
Building wheel for Octolapse (setup.py): still running...
Building wheel for Octolapse (setup.py): finished with status 'done'
Created wheel for Octolapse: filename=Octolapse-0.4.0rc3-cp27-cp27mu-linux_armv7l.whl size=3277400 sha256=ee3a12d780616d6b7ca4e7cb1402fd092ea3be34a9b94cb51980c5a16fb56753
Stored in directory: /tmp/pip-ephem-wheel-cache-cBmMrx/wheels/51/1e/30/460703132484bb4d2e97b012d270e195dd4ae1ef411932bc53
Successfully built Octolapse
Looks like the plugin was already installed. Forcing a reinstall.
/home/pi/oprint/bin/python2 -m pip --disable-pip-version-check install https://github.com/FormerLurker/Octolapse/archive/v0.4.0rc3.zip --no-cache-dir --ignore-installed --force-reinstall --no-deps
Looking in indexes: https://pypi.org/simple, https://www.piwheels.org/simple
Collecting https://github.com/FormerLurker/Octolapse/archive/v0.4.0rc3.zip
Downloading https://github.com/FormerLurker/Octolapse/archive/v0.4.0rc3.zip
Building wheels for collected packages: Octolapse
Building wheel for Octolapse (setup.py): started
Building wheel for Octolapse (setup.py): still running...
Building wheel for Octolapse (setup.py): still running...
2020-06-02 18:23:33,175 > Building wheel for Octolapse (setup.py): finished with status 'done'
2020-06-02 18:23:33,176 > Created wheel for Octolapse: filename=Octolapse-0.4.0rc3-cp27-cp27mu-linux_armv7l.whl size=3277361 sha256=9703228b83e3bf56b9003de809af5c66eda4a055b69dcce5131de35927a5961a
2020-06-02 18:23:33,176 > Stored in directory: /tmp/pip-ephem-wheel-cache-gXwHMN/wheels/51/1e/30/460703132484bb4d2e97b012d270e195dd4ae1ef411932bc53
2020-06-02 18:23:34,182 > Successfully built Octolapse
2020-06-02 18:23:34,183 > Installing collected packages: Octolapse
2020-06-02 18:23:35,552 > Successfully installed Octolapse-0.4.0rc3

Notice the very last line that reports the version. This was exactly what I expected to see.

So, this got me thinking. I uninstalled octolapse, cleaned the files, rebooted, then reinstalled from the release url, but Octoprint still thought it was a reinstall and installed the plugin twice for some reason. I then decided to more closely examine the plugin manager logs for the previous installations that had the wrong version information. I discovered that the same thing was happening in every case since I tried installing first release (the one I eventually deleted). Here is an interesting example:

So this is the last prerequisite check before octolapse is built when I first tried installing the new release (not the replacement):

2020-06-01 23:08:30,027 > Requirement already satisfied: pytz>=2015.7 in /home/pi/oprint/lib/python2.7/site-packages (from Babel>=2.3->Flask-Babel<0.13,>=0.12->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2019.3)

Notice the version number for octolapse there was correct: 0.4.0rc3

Next, Octolapse installs twice exactly as I showed earlier, and finally it reports success, BUT, here is grabs a different version number:

Successfully installed Octolapse-0.4.0rc3+u.dbe88db

Every subsequent install until I uninstalled and cleaned Octolapse reported the correct version while checking for prerequisites, and the wrong version after the second install.

Any ideas?

2

Can you share the full plugin manager log for that one? That reinstall triggers if OctoPrint sees a line generated by pip indicating that something's already there, and that's missing here. I'd like to see the full log of the installation to see what actually happened, and what kind of difference there is between the installs with right and wrong version.

You should also check if there are maybe some weird leftovers in the system with pip freeze | grep -i octolapse - especially if you mix pip install and python setup.py install calls during development, things can get confused.

3

Here is the output:

pi@octopi:~/oprint/bin $ source activate
(oprint) pi@octopi:~/oprint/bin $ pip freeze | grep -i octolapse
DEPRECATION: Python 2.7 will reach the end of its life on January 1st, 2020. Please upgrade your Python as Python 2.7 won't be maintained after that date. A future version of pip will drop support for Python 2.7. More details about Python 2 support in pip, can be found at https://pip.pypa.io/en/latest/development/release-process/#python-2-support
Octolapse==0.4.0rc3+u.68e2250

Here is the pluginmanager log file. Note that the final install shown in the log was not a release install, and the extra commit info in the version is correct there now.

4

Also, I posted here originally instead of creating a Github issue because I thought maybe someone else perhaps knew what was going on. Do you want me to create a Github issue for this? I know it's difficult to handle support requests in a forum like this. I always end up forgetting about them at some point if I don't solve them right away.

5

So what I can tell you right now is that for some reason you already/still had the exact same version installed:

2020-06-02 18:07:13,976 > Requirement already satisfied (use --upgrade to upgrade): Octolapse==0.4.0rc3 from https://github.com/FormerLurker/Octolapse/archive/v0.4.0rc3.zip in /home/pi/oprint/lib/python2.7/site-packages

And that prompted the reinstall with uncached flags. Why that then reported a wrong version number however I cannot figure out right now. I fetched the archive myself and ran python setup.py version inside and that seems to be happy, albeit reporting a pep440 incompatible version (v0.4.0rc3 instead of 0.4.0rc3).

I also just tried an install on my own development machine and I can't reproduce the version issue:

2020-06-04 11:01:32,159   C:\Devel\OctoPrint\devenv3\Scripts\python.exe -m pip --disable-pip-version-check install https://github.com/FormerLurker/Octolapse/archive/v0.4.0rc3.zip --no-cache-dir
2020-06-04 11:01:33,344 > Collecting https://github.com/FormerLurker/Octolapse/archive/v0.4.0rc3.zip
2020-06-04 11:01:34,513 > Downloading https://github.com/FormerLurker/Octolapse/archive/v0.4.0rc3.zip
2020-06-04 11:01:48,942 > Requirement already satisfied: pillow>=6.2.0<7.0.0 in c:\devel\octoprint\devenv3\lib\site-packages (from Octolapse==0.4.0rc3) (7.1.2)
2020-06-04 11:01:48,943 > Requirement already satisfied: sarge in c:\devel\octoprint\devenv3\lib\site-packages (from Octolapse==0.4.0rc3) (0.1.5.post0)
2020-06-04 11:01:48,943 > Requirement already satisfied: six in c:\devel\octoprint\devenv3\lib\site-packages (from Octolapse==0.4.0rc3) (1.14.0)
2020-06-04 11:01:48,943 > Requirement already satisfied: OctoPrint>1.3.8 in c:\devel\octoprint\octoprint\src (from Octolapse==0.4.0rc3) (1.4.1.dev262+g23a4a581a)
2020-06-04 11:01:48,943 > Requirement already satisfied: psutil in c:\devel\octoprint\devenv3\lib\site-packages (from Octolapse==0.4.0rc3) (5.7.0)
2020-06-04 11:01:48,943 > Requirement already satisfied: file_read_backwards in c:\devel\octoprint\devenv3\lib\site-packages (from Octolapse==0.4.0rc3) (2.0.0)
2020-06-04 11:01:48,943 > Requirement already satisfied: setuptools>=6.0 in c:\devel\octoprint\devenv3\lib\site-packages (from Octolapse==0.4.0rc3) (45.1.0)
2020-06-04 11:01:48,943 > Requirement already satisfied: awesome-slugify<1.7,>=1.6.5 in c:\devel\octoprint\devenv3\lib\site-packages (from Octolapse==0.4.0rc3) (1.6.5)
2020-06-04 11:01:48,943 > Requirement already satisfied: OctoPrint-FirmwareCheck>=2020.03.27 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2020.3.27)
2020-06-04 11:01:48,944 > Requirement already satisfied: markupsafe<2.0,>=1.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.1.1)
2020-06-04 11:01:48,944 > Requirement already satisfied: tornado==5.1.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (5.1.1)
2020-06-04 11:01:48,944 > Requirement already satisfied: markdown<3.2,>=3.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (3.1.1)
2020-06-04 11:01:48,944 > Requirement already satisfied: regex!=2018.11.6 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2020.5.14)
2020-06-04 11:01:48,944 > Requirement already satisfied: flask<2,>=1.1.2 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.1.2)
2020-06-04 11:01:48,944 > Requirement already satisfied: Jinja2<3,>=2.11.2 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2.11.2)
2020-06-04 11:01:48,944 > Requirement already satisfied: Flask-Login<1,>=0.5 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.5.0)
2020-06-04 11:01:48,944 > Requirement already satisfied: Flask-Babel<2,>=1.0 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.0.0)
2020-06-04 11:01:48,944 > Requirement already satisfied: Flask-Assets<3,>=2.0 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2.0)
2020-06-04 11:01:48,945 > Requirement already satisfied: blinker<2,>=1.4 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.4)
2020-06-04 11:01:48,945 > Requirement already satisfied: werkzeug<2,>=1.0.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.0.1)
2020-06-04 11:01:48,945 > Requirement already satisfied: cachelib<1,>=0.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.1)
2020-06-04 11:01:48,945 > Requirement already satisfied: PyYAML<6,>=5.3.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (5.3.1)
2020-06-04 11:01:48,945 > Requirement already satisfied: pyserial<4,>=3.4 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (3.4)
2020-06-04 11:01:48,945 > Requirement already satisfied: netaddr<1,>=0.7.19 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.7.19)
2020-06-04 11:01:48,945 > Requirement already satisfied: watchdog<1,>=0.10.2 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.10.2)
2020-06-04 11:01:48,945 > Requirement already satisfied: netifaces<1,>=0.10.9 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.10.9)
2020-06-04 11:01:48,946 > Requirement already satisfied: pylru<2,>=1.2 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.2.0)
2020-06-04 11:01:48,946 > Requirement already satisfied: rsa<5,>=4.0 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (4.0)
2020-06-04 11:01:48,946 > Requirement already satisfied: pkginfo<2,>=1.5.0.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.5.0.1)
2020-06-04 11:01:48,946 > Requirement already satisfied: requests<3,>=2.23.0 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2.23.0)
2020-06-04 11:01:48,946 > Requirement already satisfied: semantic_version<3,>=2.8.5 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2.8.5)
2020-06-04 11:01:48,946 > Requirement already satisfied: Click<8,>=7.1.2 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (7.1.2)
2020-06-04 11:01:48,946 > Requirement already satisfied: feedparser<6,>=5.2.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (5.2.1)
2020-06-04 11:01:48,946 > Requirement already satisfied: future<1,>=0.18.2 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.18.2)
2020-06-04 11:01:48,947 > Requirement already satisfied: websocket-client<1,>=0.57 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.57.0)
2020-06-04 11:01:48,947 > Requirement already satisfied: wrapt<2,>=1.12.1 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.12.1)
2020-06-04 11:01:48,947 > Requirement already satisfied: emoji<1,>=0.5.4 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.5.4)
2020-06-04 11:01:48,947 > Requirement already satisfied: frozendict<2,>=1.2 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.2)
2020-06-04 11:01:48,947 > Requirement already satisfied: sentry-sdk<1,>=0.14.4 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.14.4)
2020-06-04 11:01:48,947 > Requirement already satisfied: filetype<2,>=1.0.7 in c:\devel\octoprint\devenv3\lib\site-packages (from OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.0.7)
2020-06-04 11:01:48,947 > Requirement already satisfied: Unidecode<0.05,>=0.04.14 in c:\devel\octoprint\devenv3\lib\site-packages (from awesome-slugify<1.7,>=1.6.5->Octolapse==0.4.0rc3) (0.4.21)
2020-06-04 11:01:48,947 > Requirement already satisfied: itsdangerous>=0.24 in c:\devel\octoprint\devenv3\lib\site-packages (from flask<2,>=1.1.2->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.1.0)
2020-06-04 11:01:48,947 > Requirement already satisfied: Babel>=2.3 in c:\devel\octoprint\devenv3\lib\site-packages (from Flask-Babel<2,>=1.0->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2.8.0)
2020-06-04 11:01:48,948 > Requirement already satisfied: pytz in c:\devel\octoprint\devenv3\lib\site-packages (from Flask-Babel<2,>=1.0->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2019.3)
2020-06-04 11:01:48,948 > Requirement already satisfied: webassets>=2.0 in c:\devel\octoprint\devenv3\lib\site-packages (from Flask-Assets<3,>=2.0->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2.0)
2020-06-04 11:01:48,948 > Requirement already satisfied: pathtools>=0.1.1 in c:\devel\octoprint\devenv3\lib\site-packages (from watchdog<1,>=0.10.2->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.1.2)
2020-06-04 11:01:48,948 > Requirement already satisfied: pyasn1>=0.1.3 in c:\devel\octoprint\devenv3\lib\site-packages (from rsa<5,>=4.0->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (0.4.8)
2020-06-04 11:01:48,948 > Requirement already satisfied: certifi>=2017.4.17 in c:\devel\octoprint\devenv3\lib\site-packages (from requests<3,>=2.23.0->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2019.11.28)
2020-06-04 11:01:48,948 > Requirement already satisfied: chardet<4,>=3.0.2 in c:\devel\octoprint\devenv3\lib\site-packages (from requests<3,>=2.23.0->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (3.0.4)
2020-06-04 11:01:48,948 > Requirement already satisfied: idna<3,>=2.5 in c:\devel\octoprint\devenv3\lib\site-packages (from requests<3,>=2.23.0->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (2.8)
2020-06-04 11:01:48,948 > Requirement already satisfied: urllib3!=1.25.0,!=1.25.1,<1.26,>=1.21.1 in c:\devel\octoprint\devenv3\lib\site-packages (from requests<3,>=2.23.0->OctoPrint>1.3.8->Octolapse==0.4.0rc3) (1.25.8)
2020-06-04 11:01:48,949 > Building wheels for collected packages: Octolapse
2020-06-04 11:01:48,949 > Building wheel for Octolapse (setup.py): started
2020-06-04 11:02:49,467 > Building wheel for Octolapse (setup.py): still running...
2020-06-04 11:03:51,506 > Building wheel for Octolapse (setup.py): still running...
2020-06-04 11:04:10,087 > Building wheel for Octolapse (setup.py): finished with status 'done'
2020-06-04 11:04:10,087 > Created wheel for Octolapse: filename=Octolapse-0.4.0rc3-cp37-cp37m-win_amd64.whl size=1353732 sha256=b3e74b984ff3120653aeeee883cf96c9d24eddd155e79159471fa46f0c61d626
2020-06-04 11:04:10,087 > Stored in directory: C:\Users\Gina\AppData\Local\Temp\pip-ephem-wheel-cache-2n1ehy1c\wheels\6c\40\4c\21fa8e0e004ad3eaffb52abc000a655f22cea733bebbe1c99a
2020-06-04 11:04:10,087 > Successfully built Octolapse
2020-06-04 11:04:10,087 > Installing collected packages: Octolapse
2020-06-04 11:04:12,088 > Successfully installed Octolapse-0.4.0rc3

I'm wondering if maybe there are some weird left overs in your virtual env causing these issues. In any case, the version number that gets reported and thus installed depends on your package, that's not something that OctoPrint can control in any way, so a ticket would make no sense here (not actionable by me). I would suggest to try to reproduce in a fresh virtual env and see if it still happens.

6

I'm going to try to replicate and test this now that I've gotten Octolapse V0.4 out the door.
I should have time at some point this week. Sorry to keep you waiting!