search

metrumresearchgroup / pkgr

R package installation and management - reimagined.
https://metrumresearchgroup.github.io/pkgr/docs
39 stars 4 forks source link

Bug: not updating a package that pkgr says it will #267

Open billdenney opened 4 years ago

billdenney commented 4 years ago

I occasionally install packages outside of pkgr. When I do so, it makes sense that they show up as "Packages not installed by pkgr" while running pkgr. But, when I give the command pkgr --update install, I expected it to update even packages that I have updated outside of pkgr if they are in the pkgr.yml file. But, it doesn't.

How can I make pkgr update packages that are in my pkgr.yml file even if they were updated outside of pkgr? And as part of this bug report, if it won't do that, then the message "package will be updated" should be changed to "package will not be updated" and then it should give some form of error message.

Here is my current pkgr.yml file (but I don't think that is a notable part of the problem/question): pkgr.txt

This is on Windows 10 with pkgr version 1.0.2.

C:\git\prj\Software\Computer_Setup\Windows>pkgr --update install
INFO[0000] R Version 3.6.3
INFO[0000] found installed packages                      count=337
WARN[0000] Packages not installed by pkgr                packages="[PKdata edfun magick smoothmest influenceR survminer tabulizerjars digitizeR lotri sp maptools polynom ggpubr wmwpow pmxTools rstatix exactRankTests sf survMisc dparser KMsurv sandwich pbkrtest Rsdtm AlgDesign crossdes LogrankPower stringi rjson lamW bsd.report ggdendro microbenchmark DiagrammeRsvg formulops here visNetwork tictoc ggsci SparseM Rook latex.makers corrplot km.ci lmtest downloader MatrixModels gbRd filetype.mappings glmmML maxstat carData quantreg PKNCA tabulizer car TopicLongTable]"
INFO[0000] Default package installation type:  binary
INFO[0000] 15679:15699 (binary:source) packages available in for CRAN from https://cran.microsoft.com/snapshot/2020-05-28
INFO[0000] package will be updated                       installed_version=1.4-1 pkg=sp update_version=1.4-2
INFO[0000] package will be updated                       installed_version=0.9-9 pkg=maptools update_version=1.0-1
INFO[0000] package will be updated                       installed_version=0.8-1 pkg=sf update_version=0.9-3
INFO[0000] package will be updated                       installed_version=3.0-3 pkg=carData update_version=3.0-4
INFO[0000] package will be updated                       installed_version=0.9.1.9008 pkg=PKNCA update_version=0.9.3
INFO[0000] package will be updated                       installed_version=3.0-7 pkg=car update_version=3.0-8
INFO[0000] package installation status                   installed=337 not_from_pkgr=57 outdated=6 total_packages_required=292
INFO[0000] package installation sources                  CRAN=292 tarballs=0
INFO[0000] package installation plan                     to_install=6 to_update=6
INFO[0000] Library path to install packages: c:/Users/Bill Denney/Documents/R/win-library/3.6
INFO[0000] resolution time 413.5005ms
INFO[0000] update argument passed. staging packages for update...
INFO[0000] downloading required packages within directory   dir="C:\\Users\\Bill Denney\\AppData\\Local\\pkgr"
INFO[0000] all packages downloaded                       duration=5.0008ms
INFO[0000] starting initial install
INFO[0000] starting individual tarball install
INFO[0000] total package install time                    duration=579.501ms
INFO[0000] duration:580.0009ms

C:\git\prj\Software\Computer_Setup\Windows>pkgr --update install
INFO[0000] R Version 3.6.3
INFO[0000] found installed packages                      count=337
WARN[0000] Packages not installed by pkgr                packages="[edfun rjson car maptools sp maxstat stringi tabulizerjars visNetwork crossdes ggpubr carData digitizeR pmxTools AlgDesign exactRankTests gbRd influenceR SparseM dparser pbkrtest smoothmest sandwich here tictoc survminer latex.makers ggdendro TopicLongTable KMsurv microbenchmark PKNCA downloader LogrankPower wmwpow filetype.mappings formulops rstatix glmmML sf tabulizer magick PKdata Rsdtm quantreg lmtest km.ci ggsci polynom bsd.report lotri DiagrammeRsvg MatrixModels Rook survMisc lamW corrplot]"
INFO[0000] Default package installation type:  binary
INFO[0000] 15679:15699 (binary:source) packages available in for CRAN from https://cran.microsoft.com/snapshot/2020-05-28
INFO[0000] package will be updated                       installed_version=0.9.1.9008 pkg=PKNCA update_version=0.9.3
INFO[0000] package will be updated                       installed_version=0.8-1 pkg=sf update_version=0.9-3
INFO[0000] package will be updated                       installed_version=3.0-7 pkg=car update_version=3.0-8
INFO[0000] package will be updated                       installed_version=0.9-9 pkg=maptools update_version=1.0-1
INFO[0000] package will be updated                       installed_version=1.4-1 pkg=sp update_version=1.4-2
INFO[0000] package will be updated                       installed_version=3.0-3 pkg=carData update_version=3.0-4
INFO[0000] package installation status                   installed=337 not_from_pkgr=57 outdated=6 total_packages_required=292
INFO[0000] package installation sources                  CRAN=292 tarballs=0
INFO[0000] package installation plan                     to_install=6 to_update=6
INFO[0000] Library path to install packages: c:/Users/Bill Denney/Documents/R/win-library/3.6
INFO[0000] resolution time 386.9641ms
INFO[0000] update argument passed. staging packages for update...
INFO[0000] downloading required packages within directory   dir="C:\\Users\\Bill Denney\\AppData\\Local\\pkgr"
INFO[0000] all packages downloaded                       duration=3.9997ms
INFO[0000] starting initial install
INFO[0000] starting individual tarball install
INFO[0000] total package install time                    duration=556.5191ms
INFO[0000] duration:557.0194ms

C:\git\prj\Software\Computer_Setup\Windows>
dpastoor commented 4 years ago

Thanks for the report bill. That is not the intended behavior - as the "package will be updated" message implies, pkgr should be updating those. I can reproduce/confirm that this behavior is present, only for pkgs within the dep tree but not previously installed by pkgr. I should only not touch ones it doesn't even know what to do about/see as not in the dep tree defined by the Packages array

dpastoor commented 4 years ago

additional information - the issue is more subtle than I thought. I was really scratching my head trying to figure out how this got through our tests around updating etc. This is actually not a bug in the pkgr installation/update behavior, rather a bug in the update messages.

In your case (and mine when reproducing it quickly) is that the packages pkgr is detecting it is finding a new version in the repo and our logic basically is:

if installed + in repo --> alert that is out of date and would update

but in the your pkgr yaml (and my mega user-land one) I had actually removed all trace of packages that would get trigger them to be installed, namely, either as a dep or direct package reference, hence they were never queued up to actually update.

For example, my user-land mega pkgr shows the following plan:

INFO[0000] found installed packages                      count=591
WARN[0000] Packages not installed by pkgr                packages="[digest NMF stringi BiocManager cartographer ghpm pkgpub pkgmaker gridBase rngtools registry mpnscripts]"
INFO[0000] Default package installation type:  binary
INFO[0000] 881:881 (binary:source) packages available in for MPN from https://mpn.metworx.com/snapshots/stable/2020-05-27
INFO[0000] 15612:15769 (binary:source) packages available in for CRAN from https://cran.r-project.org
WARN[0000] outdated package found                        installed_version=2.6-10 pkg=jomo update_version=2.7-1
WARN[0000] outdated package found                        installed_version=1.3-3 pkg=party update_version=1.3-4
WARN[0000] outdated package found                        installed_version=1.4-5 pkg=vcd update_version=1.4-7
WARN[0000] outdated package found                        installed_version=0.4-18.2 pkg=robust update_version=0.5-0.0
WARN[0000] outdated package found                        installed_version=0.31 pkg=pkgmaker update_version=0.31.1
INFO[0000] package installation status                   installed=591 not_from_pkgr=12 outdated=5 total_packages_required=545
INFO[0000] package installation sources                  CRAN=23 MPN=522 tarballs=0
INFO[0000] package installation plan                     to_install=0 to_update=0
INFO[0000] Library path to install packages: 3.6
INFO[0000] resolution time 314.796538ms

By picking one of them (vcd), I do not have it as a top level package. In addition, by inspecting the reverse dependencies:

~/rpkgs pkgr inspect --deps --reverse vcd
{
  "vcd": null
}

we can see no packages depend on it. Hence, when pkgs are queued up to install and trigger additional deps to install, it never actually reaches a point to pop onto the install queue.

⋊> ~/rpkgs pkgr install --update --loglevel=trace | rg vcd                                                                                                                                                                                                              15:14:03
TRAC[0000] scanning DESCRIPTION file                     description_file=3.6/vcd/DESCRIPTION
DEBU[0000] found installed package                       package=vcd source repo=CRAN version=1.4-5
INFO[0000] package will be updated                       installed_version=1.4-5 pkg=vcd update_version=1.4-7

example showing the behavior:

Start by installing an old version of R6 not through pkgr, and setting up a super simple pkgr file that cares about R6 only

Version: 1
Threads: 8
Packages:
- R6
Repos:
  - MPN: https://mpn.metworx.com/snapshots/stable/2020-05-27
Library: 3.6

plan will show it needs to be updated:

⋊> ~/r/test pkgr plan                                                                                                                                                                                                                                                   15:17:47
INFO[0000] Installation would launch 8 workers
INFO[0000] R Version 3.6.3
INFO[0000] found installed packages                      count=1
WARN[0000] Packages not installed by pkgr                packages="[R6]"
INFO[0000] Default package installation type:  binary
INFO[0000] 881:881 (binary:source) packages available in for MPN from https://mpn.metworx.com/snapshots/stable/2020-05-27
WARN[0000] outdated package found                        installed_version=2.4.0 pkg=R6 update_version=2.4.1
INFO[0000] package installation status                   installed=1 not_from_pkgr=1 outdated=1 total_packages_required=1
INFO[0000] package installation sources                  MPN=1 tarballs=0
INFO[0000] package installation plan                     to_install=0 to_update=0
INFO[0000] Library path to install packages: 3.6
INFO[0000] resolution time 19.275953ms

Before we show it will be updated, lets change to a different package (digest) that does not depend on R6. It will tell you yes it sees both digest needing to be installed and need to update R6

Version: 1
Threads: 8
Packages:
- digest
Repos:
  - MPN: https://mpn.metworx.com/snapshots/stable/2020-05-27
Library: 3.6
⋊> ~/r/test pkgr plan --update --loglevel=debug                                                                                                                                                                                                                         15:21:07
INFO[0000] Installation would launch 8 workers
INFO[0000] R Version 3.6.3
DEBU[0000] OS Platform x86_64-apple-darwin15.6.0
DEBU[0000] found installed package                       package=R6 source repo=MPN version=2.4.0
INFO[0000] found installed packages                      count=1
WARN[0000] Packages not installed by pkgr                packages="[R6]"
INFO[0000] Default package installation type:  binary
INFO[0000] 881:881 (binary:source) packages available in for MPN from https://mpn.metworx.com/snapshots/stable/2020-05-27
DEBU[0000] package repository set                        pkg=digest relationship="user package" repo=MPN type=binary version=0.6.25
INFO[0000] package will be updated                       installed_version=2.4.0 pkg=R6 update_version=2.4.1
INFO[0000] package installation status                   installed=1 not_from_pkgr=1 outdated=1 total_packages_required=1
INFO[0000] package installation sources                  MPN=1 tarballs=0
INFO[0000] package installation plan                     to_install=2 to_update=1
INFO[0000] Library path to install packages: 3.6
INFO[0000] to install                                    package=digest repo=MPN type=binary version=0.6.25
INFO[0000] resolution time 20.119675ms

but per what we've requested, R6 is not in the top level or dep tree, therefore when we install and search for any messages around R6 lets see what happens related to R6:

⋊> ~/r/test pkgr install --update --loglevel=trace | rg R6                                                                                                                                                                                                              15:21:30
TRAC[0000] scanning DESCRIPTION file                     description_file=3.6/R6/DESCRIPTION
DEBU[0000] found installed package                       package=R6 source repo=MPN version=2.4.0
WARN[0000] Packages not installed by pkgr                packages="[R6]"
INFO[0000] package will be updated                       installed_version=2.4.0 pkg=R6 update_version=2.4.1

This will keep providing that false positive of needing to install forever:

⋊> ~/r/test pkgr plan --update --loglevel=debug                                                                                                                                                                                                                         15:23:08
INFO[0000] Installation would launch 8 workers
INFO[0000] R Version 3.6.3
DEBU[0000] OS Platform x86_64-apple-darwin15.6.0
DEBU[0000] found installed package                       package=digest source repo=MPN version=0.6.25
DEBU[0000] found installed package                       package=R6 source repo=MPN version=2.4.0
INFO[0000] found installed packages                      count=2
WARN[0000] Packages not installed by pkgr                packages="[R6]"
INFO[0000] Default package installation type:  binary
INFO[0000] 881:881 (binary:source) packages available in for MPN from https://mpn.metworx.com/snapshots/stable/2020-05-27
DEBU[0000] package repository set                        pkg=digest relationship="user package" repo=MPN type=binary version=0.6.25
INFO[0000] package will be updated                       installed_version=2.4.0 pkg=R6 update_version=2.4.1
INFO[0000] package installation status                   installed=2 not_from_pkgr=1 outdated=1 total_packages_required=1
INFO[0000] package installation sources                  MPN=1 tarballs=0
INFO[0000] package installation plan                     to_install=1 to_update=1
INFO[0000] Library path to install packages: 3.6
INFO[0000] resolution time 20.6592ms

Now instead, lets pick a package where R6 is a dep - waiter.

~/r/test pkgr install --update --loglevel=trace | rg R6                                                                                                                                                                                                              15:28:41
TRAC[0000] scanning DESCRIPTION file                     description_file=3.6/R6/DESCRIPTION
DEBU[0000] found installed package                       package=R6 source repo=MPN version=2.4.0
WARN[0000] Packages not installed by pkgr                packages="[R6]"
TRAC[0000] dep config                                    config="{true true false true false}" pkg=R6
TRAC[0000] skipping Depends dep                          dep=R pkg=R6
TRAC[0000] dep config                                    config="{true true false true false}" pkg=R6
TRAC[0000] skipping Depends dep                          dep=R pkg=R6
TRAC[0000] dep config                                    config="{true true false true false}" pkg=R6
TRAC[0000] skipping Depends dep                          dep=R pkg=R6
TRAC[0000] dep config                                    config="{true true false true false}" pkg=R6
TRAC[0000] skipping Depends dep                          dep=R pkg=R6
TRAC[0000] dep config                                    config="{true true false true false}" pkg=R6
TRAC[0000] skipping Depends dep                          dep=R pkg=R6
DEBU[0000] package repository set                        pkg=R6 relationship=dependency repo=MPN type=binary version=2.4.1
INFO[0000] package will be updated                       installed_version=2.4.0 pkg=R6 update_version=2.4.1
INFO[0000] downloading package                           package=R6
DEBU[0000] download successful                           dltime=211.477045ms package=R6 size="0.05 MB"
+TRAC[0000] pushing installation to queue                 package=R6
+TRAC[0000] package install request received              WID=6 package=R6
TRAC[0000] found in cache                                package=R6 path=/Users/devinp/rpkgs/test/pkgcache/MPN-eca5af117ae6/binary/3.6/R6_2.4.1.tgz
TRAC[0000] command args                                  RSettings="{{3 6 3} [] R {[]} map[] x86_64-apple-darwin15.6.0}" cmd=install cmdArgs="[--vanilla CMD INSTALL --install-tests --no-multiarch --with-keep.source --library=/Users/devinp/rpkgs/test/3.6 /Users/devinp/rpkgs/test/pkgcache/MPN-eca5af117ae6/binary/3.6/R6_2.4.1.tgz]" env="[CGO_CFLAGS=-g -O2 -isysroot /Library/Developer/CommandLineTools/SDKs/MacOSX.sdk CGO_CXXFLAGS=-g -O2 -isysroot /Library/Developer/CommandLineTools/SDKs/MacOSX.sdk COLORFGBG=15;0 COLORTERM=truecolor DISPLAY=/private/tmp/com.apple.launchd.E3WkecCn4n/org.macosforge.xquartz:0 GITHUB_HOST=ghe.metrumrg.com GITHUB_PAT=**HIDDEN** GITHUB_TOKEN=**HIDDEN** GO111MODULE=on GOBIN=/Users/devinp/go/bin GOPATH=/Users/devinp/go HOME=/Users/devinp ITERM_PROFILE=Default ITERM_SESSION_ID=w0t0p0:76AD0A58-A7BF-4DC6-9AD0-E866C9FCE9C5 LANG=en_US.UTF-8 LC_ALL=en_US.UTF-8 LC_TERMINAL=iTerm2 LC_TERMINAL_VERSION=3.3.9 LOGNAME=devinp LaunchInstanceID=687970D4-C477-4868-8300-781E5AF7B433 OMF_CONFIG=/Users/devinp/.config/omf OMF_PATH=/Users/devinp/.local/share/omf PATH=/usr/local/opt/gettext/bin:/Users/devinp/.cargo/bin:/Users/devinp/Library/TinyTeX/bin/x86_64-darwin:/usr/local/gfortran/bin:/usr/local/clang7/bin:/Users/devinp/go/bin:/Users/devinp/.cargo/bin:/Users/devinp/Library/TinyTeX/bin/x86_64-darwin:/usr/local/gfortran/bin:/usr/local/clang7/bin:/Users/devinp/go/bin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/opt/X11/bin:/Applications/Postgres.app/Contents/Versions/latest/bin PWD=/Users/devinp/rpkgs/test SECURITYSESSIONID=186a9 SHELL=/usr/local/bin/fish SHLVL=1 SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.6skSh5cfv1/Listeners TERM=xterm-256color TERM_PROGRAM=iTerm.app TERM_PROGRAM_VERSION=3.3.9 TERM_SESSION_ID=w0t0p0:76AD0A58-A7BF-4DC6-9AD0-E866C9FCE9C5 TMPDIR=/var/folders/bf/1cwy7ctd2k1dj13rc3v8znbh0000gn/T/ TZ=America/New_York USER=devinp XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1F5:0x0:0x0 R_LIBS_USER=/var/folders/bf/1cwy7ctd2k1dj13rc3v8znbh0000gn/T/MRTTTUPGXFGH]" package=R6
DEBU[0000] cmd output                                    exitCode=0 package=R6 stderr="* installing *binary* package ‘R6’ ...\n* DONE (R6)\n" stdout=
DEBU[0000] package install request completed             WID=6 duration=318.479335ms package=R6
DEBU[0000] R6                                            binary= src=/Users/devinp/rpkgs/test/pkgcache/MPN-eca5af117ae6/binary/3.6/R6_2.4.1.tgz
INFO[0000] Successfully Installed.                       package=R6 remaining=15 repo=MPN version=2.4.1

Now since its in the dep tree - it finds it just fine and updates it.

So the solve to your problem, is make sure your packages you want updated be somewhere in your dep tree.

@kylebaron recommended an idea i like a bit back that we haven't gotten to yet - a command something like pkgr packages sync where it would auto-add packages it detects as installed but not by pkgr to the pkgr packages array so it can manage them into the future.

billdenney commented 4 years ago

They call me Bill "Corner Case" Denney for a reason. :)

(Ok, maybe no one calls me that, but perhaps someone should.)

billdenney commented 4 years ago

As I was doing another update today, and I noticed that the "remaining" count never goes to zero. It looks like you have the issue in hand, but here is the output in case that helps:

INFO[0060] all packages downloaded                       duration=56.3254295s
INFO[0060] starting initial install
INFO[0060] Successfully Installed.                       package=glmmML remaining=21 repo=CRAN version=1.1.1
INFO[0060] Successfully Installed.                       package=later remaining=20 repo=CRAN version=1.1.0.1
INFO[0060] Successfully Installed.                       package=vctrs remaining=19 repo=CRAN version=0.3.1
INFO[0060] Successfully Installed.                       package=pkgload remaining=18 repo=CRAN version=1.1.0
INFO[0061] Successfully Installed.                       package=V8 remaining=17 repo=CRAN version=3.1.0
INFO[0061] Successfully Installed.                       package=rmarkdown remaining=16 repo=CRAN version=2.2
INFO[0061] Successfully Installed.                       package=httpuv remaining=15 repo=CRAN version=1.5.4
INFO[0061] Successfully Installed.                       package=drake remaining=14 repo=CRAN version=7.12.2
INFO[0061] Successfully Installed.                       package=dplyr remaining=13 repo=CRAN version=1.0.0
INFO[0061] Successfully Installed.                       package=haven remaining=12 repo=CRAN version=2.3.1
INFO[0061] Successfully Installed.                       package=ggplot2 remaining=11 repo=CRAN version=3.3.1
INFO[0062] Successfully Installed.                       package=GGally remaining=10 repo=CRAN version=2.0.0
INFO[0062] Successfully Installed.                       package=vpc remaining=9 repo=CRAN version=1.2.1
INFO[0062] Successfully Installed.                       package=xpose remaining=8 repo=CRAN version=0.4.10
INFO[0062] starting individual tarball install
INFO[0062] total package install time                    duration=1m2.5194683s
INFO[0062] duration:1m2.7770057s

The specific point where it stops with more packages that apparently are remaining to be installed bolded:

INFO[0062] Successfully Installed. package=xpose remaining=8 repo=CRAN version=0.4.10