Forge auto-updating pip packages?

Unless you set up something in the scheduler for that website, nothing gets updated automatically.

Are you using deployment scripts?

The default deployment script forge runs is

cd /home/forge/<domain name here>
git pull origin <deployment branch here>
composer install --no-interaction --prefer-dist --optimize-autoloader
echo "" | sudo -S service php7.1-fpm reload

if [ -f artisan ]
then
    php artisan migrate --force
fi

So whenever you deploy, it runs that (assuming you have autodeployments turned on?) You can see it does a composer install. Could that be it?

I take it back, there is one default cron job that updates composer itself (not the packages, just the composer runtime) nightly, but that shouldn't cause any of this.

I haven't set up anything in the scheduler. It's a pretty plain Laravel+forge+ottomatik setup.

Only thing I added was in the deploy script to notify BugSnag about new releases.

And I haven't touched the server for over a week. Haven't pushed anything. Hence my surprise over the backups failing. Since Pip 10 was released yesterday it's clear that something is running. But I have no idea what that something might be.

I found this file: /var/log/unattended-upgrades/unattended-upgrades.logbut there isn't anything there for the last couple of days:

2018-04-04 06:42:34,840 INFO Initial blacklisted packages:
2018-04-04 06:42:34,840 INFO Initial whitelisted packages:
2018-04-04 06:42:34,840 INFO Starting unattended upgrades script
2018-04-04 06:42:34,840 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-04 06:42:37,150 INFO No packages found that can be upgraded unattended and no pending auto-removals
2018-04-05 06:16:22,834 INFO Initial blacklisted packages:
2018-04-05 06:16:22,835 INFO Initial whitelisted packages:
2018-04-05 06:16:22,835 INFO Starting unattended upgrades script
2018-04-05 06:16:22,836 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-05 06:16:28,751 INFO Packages that will be upgraded: linux-headers-generic linux-headers-virtual linux-image-virtual linux-libc-dev linux-virtual
2018-04-05 06:16:28,752 INFO Writing dpkg log to '/var/log/unattended-upgrades/unattended-upgrades-dpkg.log'
2018-04-05 06:16:45,590 INFO All upgrades installed
2018-04-06 06:24:33,844 INFO Initial blacklisted packages:
2018-04-06 06:24:33,845 INFO Initial whitelisted packages:
2018-04-06 06:24:33,845 INFO Starting unattended upgrades script
2018-04-06 06:24:33,845 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-06 06:24:35,929 INFO No packages found that can be upgraded unattended and no pending auto-removals
2018-04-07 06:59:55,695 INFO Initial blacklisted packages:
2018-04-07 06:59:55,696 INFO Initial whitelisted packages:
2018-04-07 06:59:55,696 INFO Starting unattended upgrades script
2018-04-07 06:59:55,696 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-07 06:59:57,847 INFO No packages found that can be upgraded unattended and no pending auto-removals
2018-04-08 06:48:22,831 INFO Initial blacklisted packages:
2018-04-08 06:48:22,832 INFO Initial whitelisted packages:
2018-04-08 06:48:22,832 INFO Starting unattended upgrades script
2018-04-08 06:48:22,832 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-08 06:48:24,965 INFO No packages found that can be upgraded unattended and no pending auto-removals
2018-04-09 06:50:03,930 INFO Initial blacklisted packages:
2018-04-09 06:50:03,931 INFO Initial whitelisted packages:
2018-04-09 06:50:03,931 INFO Starting unattended upgrades script
2018-04-09 06:50:03,931 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-09 06:50:06,181 INFO No packages found that can be upgraded unattended and no pending auto-removals
2018-04-10 06:43:53,036 INFO Initial blacklisted packages:
2018-04-10 06:43:53,036 INFO Initial whitelisted packages:
2018-04-10 06:43:53,036 INFO Starting unattended upgrades script
2018-04-10 06:43:53,037 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-10 06:43:55,247 INFO No packages found that can be upgraded unattended and no pending auto-removals
2018-04-11 06:04:42,079 INFO Initial blacklisted packages:
2018-04-11 06:04:42,080 INFO Initial whitelisted packages:
2018-04-11 06:04:42,080 INFO Starting unattended upgrades script
2018-04-11 06:04:42,080 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-11 06:04:45,699 INFO Packages that will be upgraded: python3-distupgrade ubuntu-release-upgrader-core
2018-04-11 06:04:45,699 INFO Writing dpkg log to '/var/log/unattended-upgrades/unattended-upgrades-dpkg.log'
2018-04-11 06:04:48,092 INFO All upgrades installed
2018-04-12 06:13:11,242 INFO Initial blacklisted packages:
2018-04-12 06:13:11,243 INFO Initial whitelisted packages:
2018-04-12 06:13:11,243 INFO Starting unattended upgrades script
2018-04-12 06:13:11,243 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-12 06:13:14,170 INFO Packages that will be upgraded: patch
2018-04-12 06:13:14,171 INFO Writing dpkg log to '/var/log/unattended-upgrades/unattended-upgrades-dpkg.log'
2018-04-12 06:13:16,316 INFO All upgrades installed
2018-04-13 06:46:13,288 INFO Initial blacklisted packages:
2018-04-13 06:46:13,289 INFO Initial whitelisted packages:
2018-04-13 06:46:13,289 INFO Starting unattended upgrades script
2018-04-13 06:46:13,290 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-13 06:46:15,552 INFO No packages found that can be upgraded unattended and no pending auto-removals
2018-04-14 06:51:19,763 INFO Initial blacklisted packages:
2018-04-14 06:51:19,764 INFO Initial whitelisted packages:
2018-04-14 06:51:19,764 INFO Starting unattended upgrades script
2018-04-14 06:51:19,764 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-14 06:51:22,092 INFO No packages found that can be upgraded unattended and no pending auto-removals
2018-04-15 06:08:58,930 INFO Initial blacklisted packages:
2018-04-15 06:08:58,931 INFO Initial whitelisted packages:
2018-04-15 06:08:58,931 INFO Starting unattended upgrades script
2018-04-15 06:08:58,931 INFO Allowed origins are: ['o=Ubuntu,a=xenial-security']
2018-04-15 06:09:01,232 INFO No packages found that can be upgraded unattended and no pending auto-removals

Any other logs I can try to inspect for clues? I didn't see anything on the forge dashboard either...

Did you try Forge Support? It's the blue circle icon in the lower right hand corner of all Forge pages. I'm sorry, I don't know what it could be either, then, unless pip has some sort of autoupdater.

I tried to find out whether pip keeps a log or not. But from what I can tell it doesn't unless you manually use the --log argument.

You're sure your not running pip install --upgrade pip anywhere?

Haven't had tried Forge support yet, no. (Lately I've not been too impressed with response.) I'll throw them a question to see what they say.

But yea, I'm sure I haven't put in any pip install --upgrade pip myself. Haven't had any need to particularly manage them. Using forge because I wanted a more hands off experience.

I checked the time stamps on the pip libs, and it appear that pip is the only thing that got modified today:

/usr/local/lib/python2.7/dist-packages$ ls -lht
total 240K
drwxr-sr-x 2 root staff 4.0K Apr 15 07:04 pip-10.0.0.dist-info
drwxr-sr-x 4 root staff 4.0K Apr 15 07:04 pip
drwxr-sr-x 2 root staff 4.0K Apr 10 12:25 setuptools-39.0.1.dist-info
drwxr-sr-x 5 root staff 4.0K Apr 10 12:25 setuptools
drwxr-sr-x 4 root staff 4.0K Apr 10 12:25 pkg_resources
-rw-r--r-- 1 root staff  315 Apr 10 12:25 easy_install.pyc
-rw-r--r-- 1 root staff  126 Apr 10 12:25 easy_install.py
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 awscli-1.15.1.dist-info
drwxr-sr-x 6 root staff 4.0K Apr  5 20:56 awscli
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 rsa-3.4.2.dist-info
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 rsa
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 pyasn1-0.4.2.dist-info
drwxr-sr-x 5 root staff 4.0K Apr  5 20:56 pyasn1
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 s3transfer
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 s3transfer-0.1.13.dist-info
drwxr-sr-x 3 root staff 4.0K Apr  5 20:56 concurrent
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 futures-3.2.0.dist-info
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 PyYAML-3.12.dist-info
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 yaml
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 colorama
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 colorama-0.3.7.dist-info
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 botocore-1.10.1.dist-info
drwxr-sr-x 5 root staff 4.0K Apr  5 20:56 botocore
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 docutils-0.14.dist-info
drwxr-sr-x 8 root staff 4.0K Apr  5 20:56 docutils
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 python_dateutil-2.6.1.dist-info
drwxr-sr-x 4 root staff 4.0K Apr  5 20:56 dateutil
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 six-1.11.0.dist-info
-rw-r--r-- 1 root staff  30K Apr  5 20:56 six.pyc
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 jmespath-0.9.3.dist-info
drwxr-sr-x 2 root staff 4.0K Apr  5 20:56 jmespath
-rw-r--r-- 1 root staff  31K Apr  5 20:56 six.py
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 httpie-0.9.9.dist-info
drwxr-sr-x 4 root staff 4.0K Apr  3 19:14 httpie
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 requests-2.18.4.dist-info
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 requests
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 urllib3-1.22.dist-info
drwxr-sr-x 5 root staff 4.0K Apr  3 19:14 urllib3
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 idna
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 idna-2.6.dist-info
drwxr-sr-x 3 root staff 4.0K Apr  3 19:14 chardet
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 chardet-3.0.4.dist-info
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 certifi
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 certifi-2018.1.18.dist-info
drwxr-sr-x 2 root staff 4.0K Apr  3 19:14 Pygments-2.2.0.dist-info
drwxr-sr-x 6 root staff 4.0K Apr  3 19:14 pygments

I am also receiving failed back up notifications from ottomatik since 4 hours ago.

OS identified as ubuntu 16.04

OS package manager identified as apt

Python found at version: 2.7.12

Python version (2.7.12) is sufficient

Python PIP found with sufficient version (10.0.0)

PIP package python-dateutil version insufficient at:  installing
...

Installing PIP package python-dateutil >=2.4.2

#############[ FATAL ERROR ]#############

Non zero exit status (1) for:

sudo pip install "python-dateutil>=2.4.2"

With response:

sudo: no tty present and no askpass program specified

The mystery deepens

@m-rk can I presume that you also didn't touch your server today? Any explicit setup of pip updates on your server that you can recall?

(Btw, have you contacted their support? Just to bump the ticket in their court and indicate it's not an issue local to only my machine that pip changed.)

@thomthom no I didn't touch the server or pushed any code in the last ... 2 weeks at least.

I just saw my emails with the failed back up notifications. So no I didn't contact any support yet. My first reaction was to look here if anybody else was experiencing any issues ;-)

I've fired off a message to Forge support for information. (Via that widget they have on Forge dashboard, but last few times I tried that I never got a response. Had to track down the actual email address and only then did I get a reply. Seems like the widget tend to eat my messages.)

+1 from me on this Ottomatik failure. Vanilla Forge set-up.

Non zero exit status (1) for:
sudo pip install "python-dateutil>=2.4.2"
With response:
sudo: no tty present and no askpass program specified

Also seeing the same issue with Ottomatik, but only on one of several forge servers.

The question is, what caused this, some auto update on the server or something that ottomatik requres?

My last update history gives something from 3 days ago.

tail --lines=100 /var/log/apt/history.log

-Btw, isn't it doubtful that ottomatik is trying to install something-? With the new GDPR rules etc. I am considering to kick out ottomatik and take care of my backups myself. But didn't give myself the time yet to do this.

@gillidanda - do you have a sense of the age of the servers?

Maybe it's related to when they were provisioned.

I just set up a new forge server a couple of weeks ago. Migrating from an older Ubuntu 14.04 server to a new droplet. This newer server enabled some extra forge features (such as being able to update PHP etc).

I still have the old droplet and I just checked its pip version, it's still at 9.0.1.

@m-rk - same thing here. Nothing that appear relevant in the apt log on my server either.

Have you checked to see if there is anything scheduled in the OS's cron jobs (outside of forge...the actual ubuntu crontab)

/etc/crontab
/etc/cron.hourly
/etc/cron.daily
/etc/cron.weekly
/etc/cron.monthly

etc? Maybe pip added an updater in there?

crontab only shows the artisan schedule:run command and the composer self-update. All the other files are empty. I suppose this is the default from the forge servers.

Btw, isn't it doubtful that ottomatik is trying to install something?

From the error message from ottomatik it appear that it will check pip dependencies and attempt to install packages if they don't need their requirement.

But all my dependencies met the requirements. Even pip, so it should not have triggered anything.

Here's what I find in the cron job directories:

forge@skippy-ii:~$ ls /etc/cron.hourly
forge@skippy-ii:~$ ls /etc/cron.daily
apport  apt-compat  bsdmainutils  dpkg  logrotate  man-db  mdadm  mlocate  passwd  popularity-contest  sendmail  update-notifier-common
forge@skippy-ii:~$ ls /etc/cron.weekly
fstrim  man-db  update-notifier-common
forge@skippy-ii:~$ ls /etc/cron.monthly

Haven't inspected them all though.

crontab looks like this:

forge@skippy-ii:~$ cat /etc/crontab
# /etc/crontab: system-wide crontab
# Unlike any other crontab you don't have to run the `crontab'
# command to install the new version when you edit this file
# and files in /etc/cron.d. These files also have username fields,
# that none of the other crontabs do.

SHELL=/bin/sh
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin

# m h dom mon dow user  command
17 *    * * *   root    cd / && run-parts --report /etc/cron.hourly
25 6    * * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
47 6    * * 7   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.weekly )
52 6    1 * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.monthly )
#

# Laravel Forge Scheduler 261483
0 0 * * * root /usr/local/bin/composer self-update > /home/forge/.forge/scheduled-261483.log 2>&1

Yes the same for me (I suppose)

pip show python-dateutil gives me

Name: python-dateutil
Version: 2.6.1
Summary: Extensions to the standard Python datetime module
Home-page: https://dateutil.readthedocs.io
Author: Paul Ganssle
Author-email: [email protected]
License: Simplified BSD
Location: /usr/local/lib/python2.7/dist-packages
Requires: six
Required-by: botocore

Now I'm getting messages from Ottomatik every 5 minutes...

Interesting, just triggered a manual backup and now I got the following error:

ython PIP found with sufficient version (10.0.0)

PIP package python-dateutil found at 2.6.1 OK

PIP package futures version insufficient at:  installing...

Installing PIP package futures >=3.0.5

#############[ FATAL ERROR ]#############

Non zero exit status (1) for:

sudo pip install "futures>=3.0.5"

With response:

sudo: no tty present and no askpass program specified

python-dateutil is now found, but now it complains about another package...

@thomthom

Just got the following reply from ottomatik

Hello, thank you for the update - we are working on this issue now, it looks like it's caused due to pip version 10 (forge must have auto-updated this).

Ottomatik is activly working updates right now. Hence the errors changing.

My pip directory is updated today at 12:00 utc-0 so that explains something. No clue though what triggered this update or where you are able to see this history in a log like the apt updates.

# path /usr/local/lib/python2.7/dist-packages
drwxr-sr-x 4 root staff  4096 Apr 15 12:03 pip

@thomthom @Cronix I've just found the cause of the mystery pip update. It is the letsencrypt renewal.

Requirement already up-to-date: setuptools in /usr/local/lib/python2.7/dist-packages
Installing collected packages: pip
  Found existing installation: pip 9.0.3
    Uninstalling pip-9.0.3:
      Successfully uninstalled pip-9.0.3
Successfully installed pip-10.0.0

You can find this log in this directory:/home/forge/.letsencrypt-renew/ and than probably pick the last file with an *.out extension

That's really **itty of letsencrypt to do. My goodness lol. Do they not think anyone else is relying on pip? Especially when it introduces breaking changes.

I think it is not letsencrypt itself but forge that is causing this. The code below is part of a microservice from forge that is being used to renew the certificate

# Install setuptools

echo "Installing Python setuptools..."

pip install -U pip setuptools

# Install Shell Client

echo "Installing LetsEncrypt client..."

And the pip install here caused the update from 9 to 10