MultiEval Example

This notebook demonstrates a basic parameter sweep with LensKits MultiEval class.

Setup

We first need to import our libraries.

In [1]:
from lenskit.batch import MultiEval
from lenskit.crossfold import partition_users, SampleN
from lenskit.algorithms import basic, als
from lenskit.datasets import MovieLens
from lenskit import topn, util
import pandas as pd
import matplotlib.pyplot as plt

Progress bars are useful:

In [2]:
from tqdm.notebook import tqdm_notebook as tqdm
tqdm.pandas()
C:\Users\michaelekstrand\Anaconda3\envs\lkpy-dev\lib\site-packages\tqdm\std.py:668: FutureWarning: The Panel class is removed from pandas. Accessing it from the top-level namespace will also be removed in the next version
  from pandas import Panel

It takes a little while to run things, and can get kinda quiet in here. Let's set up logging so we can see the logging output in the notebook's message stream:

In [3]:
util.log_to_notebook()
[   INFO] lenskit.util.log notebook logging configured

Then set up the data access.

In [4]:
mlsmall = MovieLens('../data/ml-latest-small')

Experiment

We're going to run our evaluation and store its output in the my-eval directory, generating 20-item recommendation lists::

In [5]:
eval = MultiEval('my-eval', recommend=20)

We're going to use a 5-fold cross-validation setup. We save the data into a list in memory so we have access to the test data later. In a larger experiment, you might write the partitions to disk and pass the file names to add_datasets.

In [6]:
pairs = list(partition_users(mlsmall.ratings, 5, SampleN(5)))
eval.add_datasets(pairs, name='ML-Small')
[   INFO] lenskit.crossfold partitioning 100004 rows for 671 users into 5 partitions
[   INFO] lenskit.crossfold fold 0: selecting test ratings
[   INFO] lenskit.crossfold fold 0: partitioning training data
[   INFO] lenskit.crossfold fold 1: selecting test ratings
[   INFO] lenskit.crossfold fold 1: partitioning training data
[   INFO] lenskit.crossfold fold 2: selecting test ratings
[   INFO] lenskit.crossfold fold 2: partitioning training data
[   INFO] lenskit.crossfold fold 3: selecting test ratings
[   INFO] lenskit.crossfold fold 3: partitioning training data
[   INFO] lenskit.crossfold fold 4: selecting test ratings
[   INFO] lenskit.crossfold fold 4: partitioning training data

We're going to test explicit MF with several neighborhood sizes:

In [7]:
eval.add_algorithms([als.BiasedMF(f) for f in [20, 30, 40, 50]],
                    attrs=['features'], name='BiasedMF')

And implicit MF:

In [8]:
eval.add_algorithms([als.ImplicitMF(f) for f in [20, 30, 40, 50]],
                    attrs=['features'], name='ImplicitMF')

And add a popular baseline for comparison:

In [9]:
eval.add_algorithms(basic.Popular(), name='Pop')

And finally, we will run the experiment!

In [10]:
eval.run(progress=tqdm)
[   INFO] lenskit.batch._multi starting run 1: als.BiasedMF(features=20, regularization=0.1) on ML-Small:1
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=20, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=20, regularization=0.1) on 99329 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99329 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9060 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 351ms] normalizing 671x9060 matrix (99329 nnz)
[   INFO] lenskit.algorithms.als [1.75s] training biased MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als [5.15s] finished epoch 0 (|ΔP|=32.144, |ΔQ|=124.881)
[   INFO] lenskit.algorithms.als [5.17s] finished epoch 1 (|ΔP|=12.154, |ΔQ|=51.625)
[   INFO] lenskit.algorithms.als [5.18s] finished epoch 2 (|ΔP|=8.825, |ΔQ|=27.235)
[   INFO] lenskit.algorithms.als [5.19s] finished epoch 3 (|ΔP|=6.144, |ΔQ|=17.365)
[   INFO] lenskit.algorithms.als [5.20s] finished epoch 4 (|ΔP|=4.521, |ΔQ|=12.784)
[   INFO] lenskit.algorithms.als [5.22s] finished epoch 5 (|ΔP|=3.526, |ΔQ|=9.939)
[   INFO] lenskit.algorithms.als [5.24s] finished epoch 6 (|ΔP|=2.876, |ΔQ|=8.045)
[   INFO] lenskit.algorithms.als [5.25s] finished epoch 7 (|ΔP|=2.418, |ΔQ|=6.724)
[   INFO] lenskit.algorithms.als [5.27s] finished epoch 8 (|ΔP|=2.080, |ΔQ|=5.767)
[   INFO] lenskit.algorithms.als [5.28s] finished epoch 9 (|ΔP|=1.823, |ΔQ|=5.051)
[   INFO] lenskit.algorithms.als [5.29s] finished epoch 10 (|ΔP|=1.623, |ΔQ|=4.494)
[   INFO] lenskit.algorithms.als [5.31s] finished epoch 11 (|ΔP|=1.462, |ΔQ|=4.043)
[   INFO] lenskit.algorithms.als [5.32s] finished epoch 12 (|ΔP|=1.326, |ΔQ|=3.665)
[   INFO] lenskit.algorithms.als [5.33s] finished epoch 13 (|ΔP|=1.208, |ΔQ|=3.344)
[   INFO] lenskit.algorithms.als [5.35s] finished epoch 14 (|ΔP|=1.104, |ΔQ|=3.068)
[   INFO] lenskit.algorithms.als [5.36s] finished epoch 15 (|ΔP|=1.013, |ΔQ|=2.828)
[   INFO] lenskit.algorithms.als [5.38s] finished epoch 16 (|ΔP|=0.932, |ΔQ|=2.619)
[   INFO] lenskit.algorithms.als [5.39s] finished epoch 17 (|ΔP|=0.861, |ΔQ|=2.435)
[   INFO] lenskit.algorithms.als [5.40s] finished epoch 18 (|ΔP|=0.797, |ΔQ|=2.270)
[   INFO] lenskit.algorithms.als [5.41s] finished epoch 19 (|ΔP|=0.740, |ΔQ|=2.122)
[   INFO] lenskit.algorithms.als trained model in 5.41s (|P|=29.700828, |Q|=94.427435)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=20, regularization=0.1) in 5.43s
[   INFO] lenskit.batch._multi generating 675 predictions for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-u7bm2cqz.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 675 predictions for 135 users
[   INFO] lenskit.batch._multi generated predictions in 2.07s
[   INFO] lenskit.batch._multi run 1: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 135 users for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-7t4oer0n.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=20, regularization=0.1) for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in 1.93s
[   INFO] lenskit.batch._multi generated recommendations in 2.14s
[   INFO] lenskit.batch._multi run 1: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 1: als.BiasedMF(features=20, regularization=0.1) on ML-Small:1
[   INFO] lenskit.batch._multi starting run 2: als.BiasedMF(features=30, regularization=0.1) on ML-Small:1
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=30, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=30, regularization=0.1) on 99329 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99329 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9060 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 47ms] normalizing 671x9060 matrix (99329 nnz)
[   INFO] lenskit.algorithms.als [ 57ms] training biased MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als [ 75ms] finished epoch 0 (|ΔP|=33.389, |ΔQ|=126.440)
[   INFO] lenskit.algorithms.als [ 92ms] finished epoch 1 (|ΔP|=12.618, |ΔQ|=53.305)
[   INFO] lenskit.algorithms.als [ 109ms] finished epoch 2 (|ΔP|=9.101, |ΔQ|=27.239)
[   INFO] lenskit.algorithms.als [ 127ms] finished epoch 3 (|ΔP|=6.112, |ΔQ|=17.111)
[   INFO] lenskit.algorithms.als [ 144ms] finished epoch 4 (|ΔP|=4.402, |ΔQ|=12.463)
[   INFO] lenskit.algorithms.als [ 161ms] finished epoch 5 (|ΔP|=3.364, |ΔQ|=9.626)
[   INFO] lenskit.algorithms.als [ 178ms] finished epoch 6 (|ΔP|=2.694, |ΔQ|=7.761)
[   INFO] lenskit.algorithms.als [ 196ms] finished epoch 7 (|ΔP|=2.235, |ΔQ|=6.455)
[   INFO] lenskit.algorithms.als [ 213ms] finished epoch 8 (|ΔP|=1.903, |ΔQ|=5.496)
[   INFO] lenskit.algorithms.als [ 231ms] finished epoch 9 (|ΔP|=1.656, |ΔQ|=4.769)
[   INFO] lenskit.algorithms.als [ 246ms] finished epoch 10 (|ΔP|=1.466, |ΔQ|=4.205)
[   INFO] lenskit.algorithms.als [ 264ms] finished epoch 11 (|ΔP|=1.315, |ΔQ|=3.757)
[   INFO] lenskit.algorithms.als [ 282ms] finished epoch 12 (|ΔP|=1.193, |ΔQ|=3.392)
[   INFO] lenskit.algorithms.als [ 303ms] finished epoch 13 (|ΔP|=1.091, |ΔQ|=3.088)
[   INFO] lenskit.algorithms.als [ 328ms] finished epoch 14 (|ΔP|=1.002, |ΔQ|=2.828)
[   INFO] lenskit.algorithms.als [ 348ms] finished epoch 15 (|ΔP|=0.924, |ΔQ|=2.605)
[   INFO] lenskit.algorithms.als [ 368ms] finished epoch 16 (|ΔP|=0.855, |ΔQ|=2.409)
[   INFO] lenskit.algorithms.als [ 385ms] finished epoch 17 (|ΔP|=0.794, |ΔQ|=2.235)
[   INFO] lenskit.algorithms.als [ 408ms] finished epoch 18 (|ΔP|=0.739, |ΔQ|=2.080)
[   INFO] lenskit.algorithms.als [ 426ms] finished epoch 19 (|ΔP|=0.690, |ΔQ|=1.941)
[   INFO] lenskit.algorithms.als trained model in  428ms (|P|=30.758338, |Q|=94.572805)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=30, regularization=0.1) in  444ms
[   INFO] lenskit.batch._multi generating 675 predictions for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-2ndjw7ry.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 675 predictions for 135 users
[   INFO] lenskit.batch._multi generated predictions in 2.01s
[   INFO] lenskit.batch._multi run 2: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 135 users for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-z40nh6m_.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=30, regularization=0.1) for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in 1.94s
[   INFO] lenskit.batch._multi generated recommendations in 2.14s
[   INFO] lenskit.batch._multi run 2: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 2: als.BiasedMF(features=30, regularization=0.1) on ML-Small:1
[   INFO] lenskit.batch._multi starting run 3: als.BiasedMF(features=40, regularization=0.1) on ML-Small:1
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=40, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=40, regularization=0.1) on 99329 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99329 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9060 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 43ms] normalizing 671x9060 matrix (99329 nnz)
[   INFO] lenskit.algorithms.als [ 53ms] training biased MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als [ 76ms] finished epoch 0 (|ΔP|=33.959, |ΔQ|=127.846)
[   INFO] lenskit.algorithms.als [ 94ms] finished epoch 1 (|ΔP|=12.694, |ΔQ|=53.672)
[   INFO] lenskit.algorithms.als [ 116ms] finished epoch 2 (|ΔP|=9.463, |ΔQ|=27.371)
[   INFO] lenskit.algorithms.als [ 136ms] finished epoch 3 (|ΔP|=6.247, |ΔQ|=17.225)
[   INFO] lenskit.algorithms.als [ 157ms] finished epoch 4 (|ΔP|=4.450, |ΔQ|=12.667)
[   INFO] lenskit.algorithms.als [ 178ms] finished epoch 5 (|ΔP|=3.398, |ΔQ|=9.835)
[   INFO] lenskit.algorithms.als [ 199ms] finished epoch 6 (|ΔP|=2.718, |ΔQ|=7.898)
[   INFO] lenskit.algorithms.als [ 219ms] finished epoch 7 (|ΔP|=2.240, |ΔQ|=6.497)
[   INFO] lenskit.algorithms.als [ 242ms] finished epoch 8 (|ΔP|=1.881, |ΔQ|=5.444)
[   INFO] lenskit.algorithms.als [ 263ms] finished epoch 9 (|ΔP|=1.602, |ΔQ|=4.623)
[   INFO] lenskit.algorithms.als [ 283ms] finished epoch 10 (|ΔP|=1.382, |ΔQ|=3.969)
[   INFO] lenskit.algorithms.als [ 303ms] finished epoch 11 (|ΔP|=1.207, |ΔQ|=3.449)
[   INFO] lenskit.algorithms.als [ 325ms] finished epoch 12 (|ΔP|=1.066, |ΔQ|=3.034)
[   INFO] lenskit.algorithms.als [ 345ms] finished epoch 13 (|ΔP|=0.952, |ΔQ|=2.696)
[   INFO] lenskit.algorithms.als [ 367ms] finished epoch 14 (|ΔP|=0.857, |ΔQ|=2.416)
[   INFO] lenskit.algorithms.als [ 389ms] finished epoch 15 (|ΔP|=0.778, |ΔQ|=2.184)
[   INFO] lenskit.algorithms.als [ 411ms] finished epoch 16 (|ΔP|=0.710, |ΔQ|=1.988)
[   INFO] lenskit.algorithms.als [ 437ms] finished epoch 17 (|ΔP|=0.653, |ΔQ|=1.823)
[   INFO] lenskit.algorithms.als [ 459ms] finished epoch 18 (|ΔP|=0.603, |ΔQ|=1.680)
[   INFO] lenskit.algorithms.als [ 480ms] finished epoch 19 (|ΔP|=0.559, |ΔQ|=1.557)
[   INFO] lenskit.algorithms.als trained model in  482ms (|P|=31.269929, |Q|=94.607805)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=40, regularization=0.1) in  497ms
[   INFO] lenskit.batch._multi generating 675 predictions for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-twz757ey.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 675 predictions for 135 users
[   INFO] lenskit.batch._multi generated predictions in 1.94s
[   INFO] lenskit.batch._multi run 3: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 135 users for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-h9t1159u.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=40, regularization=0.1) for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in 1.90s
[   INFO] lenskit.batch._multi generated recommendations in 2.10s
[   INFO] lenskit.batch._multi run 3: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 3: als.BiasedMF(features=40, regularization=0.1) on ML-Small:1
[   INFO] lenskit.batch._multi starting run 4: als.BiasedMF(features=50, regularization=0.1) on ML-Small:1
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=50, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=50, regularization=0.1) on 99329 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99329 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9060 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 39ms] normalizing 671x9060 matrix (99329 nnz)
[   INFO] lenskit.algorithms.als [ 51ms] training biased MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als [ 77ms] finished epoch 0 (|ΔP|=34.091, |ΔQ|=129.715)
[   INFO] lenskit.algorithms.als [ 104ms] finished epoch 1 (|ΔP|=13.058, |ΔQ|=54.441)
[   INFO] lenskit.algorithms.als [ 131ms] finished epoch 2 (|ΔP|=9.363, |ΔQ|=26.598)
[   INFO] lenskit.algorithms.als [ 160ms] finished epoch 3 (|ΔP|=6.077, |ΔQ|=16.994)
[   INFO] lenskit.algorithms.als [ 189ms] finished epoch 4 (|ΔP|=4.277, |ΔQ|=12.344)
[   INFO] lenskit.algorithms.als [ 219ms] finished epoch 5 (|ΔP|=3.217, |ΔQ|=9.458)
[   INFO] lenskit.algorithms.als [ 248ms] finished epoch 6 (|ΔP|=2.537, |ΔQ|=7.531)
[   INFO] lenskit.algorithms.als [ 278ms] finished epoch 7 (|ΔP|=2.065, |ΔQ|=6.154)
[   INFO] lenskit.algorithms.als [ 308ms] finished epoch 8 (|ΔP|=1.718, |ΔQ|=5.128)
[   INFO] lenskit.algorithms.als [ 338ms] finished epoch 9 (|ΔP|=1.454, |ΔQ|=4.345)
[   INFO] lenskit.algorithms.als [ 364ms] finished epoch 10 (|ΔP|=1.249, |ΔQ|=3.735)
[   INFO] lenskit.algorithms.als [ 394ms] finished epoch 11 (|ΔP|=1.087, |ΔQ|=3.247)
[   INFO] lenskit.algorithms.als [ 422ms] finished epoch 12 (|ΔP|=0.956, |ΔQ|=2.850)
[   INFO] lenskit.algorithms.als [ 450ms] finished epoch 13 (|ΔP|=0.848, |ΔQ|=2.523)
[   INFO] lenskit.algorithms.als [ 473ms] finished epoch 14 (|ΔP|=0.760, |ΔQ|=2.253)
[   INFO] lenskit.algorithms.als [ 502ms] finished epoch 15 (|ΔP|=0.685, |ΔQ|=2.026)
[   INFO] lenskit.algorithms.als [ 530ms] finished epoch 16 (|ΔP|=0.622, |ΔQ|=1.834)
[   INFO] lenskit.algorithms.als [ 558ms] finished epoch 17 (|ΔP|=0.569, |ΔQ|=1.668)
[   INFO] lenskit.algorithms.als [ 586ms] finished epoch 18 (|ΔP|=0.522, |ΔQ|=1.525)
[   INFO] lenskit.algorithms.als [ 616ms] finished epoch 19 (|ΔP|=0.482, |ΔQ|=1.401)
[   INFO] lenskit.algorithms.als trained model in  617ms (|P|=31.497696, |Q|=94.629892)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=50, regularization=0.1) in  633ms
[   INFO] lenskit.batch._multi generating 675 predictions for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-3z9t_6nn.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 675 predictions for 135 users
[   INFO] lenskit.batch._multi generated predictions in 1.89s
[   INFO] lenskit.batch._multi run 4: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 135 users for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-2cdh2vca.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=50, regularization=0.1) for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in 1.87s
[   INFO] lenskit.batch._multi generated recommendations in 2.06s
[   INFO] lenskit.batch._multi run 4: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 4: als.BiasedMF(features=50, regularization=0.1) on ML-Small:1
[   INFO] lenskit.batch._multi starting run 5: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:1
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=20, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=20, reg=0.1, w=40) on 99329 ratings
[   INFO] lenskit.algorithms.als [ 12ms] training implicit MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als have 99329 observations for 671 users and 9060 items
[   INFO] lenskit.algorithms.als [7.19s] finished epoch 0 (|ΔP|=3394.400, |ΔQ|=8.617)
[   INFO] lenskit.algorithms.als [7.24s] finished epoch 1 (|ΔP|=182.264, |ΔQ|=3.453)
[   INFO] lenskit.algorithms.als [7.28s] finished epoch 2 (|ΔP|=72.796, |ΔQ|=2.408)
[   INFO] lenskit.algorithms.als [7.33s] finished epoch 3 (|ΔP|=67.947, |ΔQ|=1.849)
[   INFO] lenskit.algorithms.als [7.37s] finished epoch 4 (|ΔP|=79.469, |ΔQ|=1.574)
[   INFO] lenskit.algorithms.als [7.42s] finished epoch 5 (|ΔP|=95.785, |ΔQ|=1.373)
[   INFO] lenskit.algorithms.als [7.46s] finished epoch 6 (|ΔP|=78.213, |ΔQ|=1.164)
[   INFO] lenskit.algorithms.als [7.51s] finished epoch 7 (|ΔP|=80.585, |ΔQ|=1.003)
[   INFO] lenskit.algorithms.als [7.55s] finished epoch 8 (|ΔP|=76.428, |ΔQ|=0.873)
[   INFO] lenskit.algorithms.als [7.60s] finished epoch 9 (|ΔP|=75.034, |ΔQ|=0.791)
[   INFO] lenskit.algorithms.als [7.65s] finished epoch 10 (|ΔP|=65.064, |ΔQ|=0.711)
[   INFO] lenskit.algorithms.als [7.70s] finished epoch 11 (|ΔP|=85.484, |ΔQ|=0.695)
[   INFO] lenskit.algorithms.als [7.74s] finished epoch 12 (|ΔP|=60.615, |ΔQ|=0.600)
[   INFO] lenskit.algorithms.als [7.79s] finished epoch 13 (|ΔP|=63.237, |ΔQ|=0.581)
[   INFO] lenskit.algorithms.als [7.83s] finished epoch 14 (|ΔP|=56.944, |ΔQ|=0.538)
[   INFO] lenskit.algorithms.als [7.88s] finished epoch 15 (|ΔP|=65.895, |ΔQ|=0.529)
[   INFO] lenskit.algorithms.als [7.92s] finished epoch 16 (|ΔP|=54.112, |ΔQ|=0.495)
[   INFO] lenskit.algorithms.als [7.97s] finished epoch 17 (|ΔP|=55.742, |ΔQ|=0.471)
[   INFO] lenskit.algorithms.als [8.01s] finished epoch 18 (|ΔP|=59.130, |ΔQ|=0.455)
[   INFO] lenskit.algorithms.als [8.06s] finished epoch 19 (|ΔP|=64.630, |ΔQ|=0.437)
[   INFO] lenskit.algorithms.als [8.06s] finished training model with 20 features (|P|=2561.324204, |Q|=9.382931)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=20, reg=0.1, w=40) in 8.07s
[   INFO] lenskit.batch._multi generating 675 predictions for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-dxt69lgp.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 675 predictions for 135 users
[   INFO] lenskit.batch._multi generated predictions in 2.43s
[   INFO] lenskit.batch._multi run 5: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 135 users for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-t2nimnyr.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=20, reg=0.1, w=40) for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in 1.90s
[   INFO] lenskit.batch._multi generated recommendations in 2.10s
[   INFO] lenskit.batch._multi run 5: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 5: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:1
[   INFO] lenskit.batch._multi starting run 6: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:1
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=30, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=30, reg=0.1, w=40) on 99329 ratings
[   INFO] lenskit.algorithms.als [ 15ms] training implicit MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als have 99329 observations for 671 users and 9060 items
[   INFO] lenskit.algorithms.als [ 66ms] finished epoch 0 (|ΔP|=3823.401, |ΔQ|=8.176)
[   INFO] lenskit.algorithms.als [ 116ms] finished epoch 1 (|ΔP|=197.089, |ΔQ|=3.204)
[   INFO] lenskit.algorithms.als [ 166ms] finished epoch 2 (|ΔP|=112.848, |ΔQ|=2.102)
[   INFO] lenskit.algorithms.als [ 216ms] finished epoch 3 (|ΔP|=120.734, |ΔQ|=1.643)
[   INFO] lenskit.algorithms.als [ 267ms] finished epoch 4 (|ΔP|=128.267, |ΔQ|=1.291)
[   INFO] lenskit.algorithms.als [ 317ms] finished epoch 5 (|ΔP|=123.323, |ΔQ|=1.038)
[   INFO] lenskit.algorithms.als [ 368ms] finished epoch 6 (|ΔP|=103.669, |ΔQ|=0.860)
[   INFO] lenskit.algorithms.als [ 418ms] finished epoch 7 (|ΔP|=97.214, |ΔQ|=0.746)
[   INFO] lenskit.algorithms.als [ 468ms] finished epoch 8 (|ΔP|=92.921, |ΔQ|=0.677)
[   INFO] lenskit.algorithms.als [ 519ms] finished epoch 9 (|ΔP|=85.104, |ΔQ|=0.591)
[   INFO] lenskit.algorithms.als [ 571ms] finished epoch 10 (|ΔP|=84.155, |ΔQ|=0.555)
[   INFO] lenskit.algorithms.als [ 624ms] finished epoch 11 (|ΔP|=84.841, |ΔQ|=0.519)
[   INFO] lenskit.algorithms.als [ 674ms] finished epoch 12 (|ΔP|=80.127, |ΔQ|=0.482)
[   INFO] lenskit.algorithms.als [ 723ms] finished epoch 13 (|ΔP|=75.243, |ΔQ|=0.449)
[   INFO] lenskit.algorithms.als [ 774ms] finished epoch 14 (|ΔP|=79.453, |ΔQ|=0.437)
[   INFO] lenskit.algorithms.als [ 824ms] finished epoch 15 (|ΔP|=72.474, |ΔQ|=0.406)
[   INFO] lenskit.algorithms.als [ 874ms] finished epoch 16 (|ΔP|=70.143, |ΔQ|=0.389)
[   INFO] lenskit.algorithms.als [ 924ms] finished epoch 17 (|ΔP|=64.952, |ΔQ|=0.362)
[   INFO] lenskit.algorithms.als [ 974ms] finished epoch 18 (|ΔP|=86.699, |ΔQ|=0.384)
[   INFO] lenskit.algorithms.als [1.02s] finished epoch 19 (|ΔP|=67.358, |ΔQ|=0.341)
[   INFO] lenskit.algorithms.als [1.03s] finished training model with 30 features (|P|=2747.236676, |Q|=8.939173)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=30, reg=0.1, w=40) in 1.04s
[   INFO] lenskit.batch._multi generating 675 predictions for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-08825cx6.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 675 predictions for 135 users
[   INFO] lenskit.batch._multi generated predictions in 1.97s
[   INFO] lenskit.batch._multi run 6: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 135 users for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-smg_wepd.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=30, reg=0.1, w=40) for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in 1.89s
[   INFO] lenskit.batch._multi generated recommendations in 2.09s
[   INFO] lenskit.batch._multi run 6: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 6: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:1
[   INFO] lenskit.batch._multi starting run 7: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:1
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=40, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=40, reg=0.1, w=40) on 99329 ratings
[   INFO] lenskit.algorithms.als [ 15ms] training implicit MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als have 99329 observations for 671 users and 9060 items
[   INFO] lenskit.algorithms.als [ 67ms] finished epoch 0 (|ΔP|=4093.762, |ΔQ|=7.804)
[   INFO] lenskit.algorithms.als [ 117ms] finished epoch 1 (|ΔP|=208.600, |ΔQ|=2.987)
[   INFO] lenskit.algorithms.als [ 168ms] finished epoch 2 (|ΔP|=149.912, |ΔQ|=1.974)
[   INFO] lenskit.algorithms.als [ 217ms] finished epoch 3 (|ΔP|=176.388, |ΔQ|=1.547)
[   INFO] lenskit.algorithms.als [ 268ms] finished epoch 4 (|ΔP|=173.788, |ΔQ|=1.220)
[   INFO] lenskit.algorithms.als [ 319ms] finished epoch 5 (|ΔP|=141.926, |ΔQ|=0.981)
[   INFO] lenskit.algorithms.als [ 371ms] finished epoch 6 (|ΔP|=136.706, |ΔQ|=0.851)
[   INFO] lenskit.algorithms.als [ 424ms] finished epoch 7 (|ΔP|=112.828, |ΔQ|=0.738)
[   INFO] lenskit.algorithms.als [ 477ms] finished epoch 8 (|ΔP|=112.288, |ΔQ|=0.669)
[   INFO] lenskit.algorithms.als [ 533ms] finished epoch 9 (|ΔP|=100.770, |ΔQ|=0.597)
[   INFO] lenskit.algorithms.als [ 586ms] finished epoch 10 (|ΔP|=98.509, |ΔQ|=0.558)
[   INFO] lenskit.algorithms.als [ 638ms] finished epoch 11 (|ΔP|=95.546, |ΔQ|=0.516)
[   INFO] lenskit.algorithms.als [ 692ms] finished epoch 12 (|ΔP|=102.065, |ΔQ|=0.508)
[   INFO] lenskit.algorithms.als [ 746ms] finished epoch 13 (|ΔP|=80.462, |ΔQ|=0.449)
[   INFO] lenskit.algorithms.als [ 799ms] finished epoch 14 (|ΔP|=91.638, |ΔQ|=0.447)
[   INFO] lenskit.algorithms.als [ 851ms] finished epoch 15 (|ΔP|=72.832, |ΔQ|=0.401)
[   INFO] lenskit.algorithms.als [ 903ms] finished epoch 16 (|ΔP|=93.824, |ΔQ|=0.414)
[   INFO] lenskit.algorithms.als [ 953ms] finished epoch 17 (|ΔP|=70.742, |ΔQ|=0.367)
[   INFO] lenskit.algorithms.als [1.01s] finished epoch 18 (|ΔP|=84.424, |ΔQ|=0.379)
[   INFO] lenskit.algorithms.als [1.06s] finished epoch 19 (|ΔP|=60.118, |ΔQ|=0.334)
[   INFO] lenskit.algorithms.als [1.06s] finished training model with 40 features (|P|=2709.409153, |Q|=8.833095)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=40, reg=0.1, w=40) in 1.08s
[   INFO] lenskit.batch._multi generating 675 predictions for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-w6e94233.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 675 predictions for 135 users
[   INFO] lenskit.batch._multi generated predictions in 1.88s
[   INFO] lenskit.batch._multi run 7: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 135 users for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-28ty379_.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=40, reg=0.1, w=40) for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in 1.88s
[   INFO] lenskit.batch._multi generated recommendations in 2.08s
[   INFO] lenskit.batch._multi run 7: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 7: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:1
[   INFO] lenskit.batch._multi starting run 8: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:1
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=50, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=50, reg=0.1, w=40) on 99329 ratings
[   INFO] lenskit.algorithms.als [ 17ms] training implicit MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als have 99329 observations for 671 users and 9060 items
[   INFO] lenskit.algorithms.als [ 70ms] finished epoch 0 (|ΔP|=4333.527, |ΔQ|=7.367)
[   INFO] lenskit.algorithms.als [ 126ms] finished epoch 1 (|ΔP|=239.854, |ΔQ|=2.826)
[   INFO] lenskit.algorithms.als [ 182ms] finished epoch 2 (|ΔP|=223.144, |ΔQ|=1.855)
[   INFO] lenskit.algorithms.als [ 239ms] finished epoch 3 (|ΔP|=243.062, |ΔQ|=1.386)
[   INFO] lenskit.algorithms.als [ 296ms] finished epoch 4 (|ΔP|=216.502, |ΔQ|=1.080)
[   INFO] lenskit.algorithms.als [ 354ms] finished epoch 5 (|ΔP|=170.931, |ΔQ|=0.881)
[   INFO] lenskit.algorithms.als [ 417ms] finished epoch 6 (|ΔP|=155.900, |ΔQ|=0.762)
[   INFO] lenskit.algorithms.als [ 480ms] finished epoch 7 (|ΔP|=141.542, |ΔQ|=0.676)
[   INFO] lenskit.algorithms.als [ 535ms] finished epoch 8 (|ΔP|=135.273, |ΔQ|=0.614)
[   INFO] lenskit.algorithms.als [ 591ms] finished epoch 9 (|ΔP|=124.747, |ΔQ|=0.554)
[   INFO] lenskit.algorithms.als [ 647ms] finished epoch 10 (|ΔP|=114.954, |ΔQ|=0.509)
[   INFO] lenskit.algorithms.als [ 704ms] finished epoch 11 (|ΔP|=116.077, |ΔQ|=0.481)
[   INFO] lenskit.algorithms.als [ 760ms] finished epoch 12 (|ΔP|=112.371, |ΔQ|=0.454)
[   INFO] lenskit.algorithms.als [ 816ms] finished epoch 13 (|ΔP|=106.791, |ΔQ|=0.433)
[   INFO] lenskit.algorithms.als [ 873ms] finished epoch 14 (|ΔP|=101.498, |ΔQ|=0.407)
[   INFO] lenskit.algorithms.als [ 928ms] finished epoch 15 (|ΔP|=100.090, |ΔQ|=0.391)
[   INFO] lenskit.algorithms.als [ 985ms] finished epoch 16 (|ΔP|=99.442, |ΔQ|=0.372)
[   INFO] lenskit.algorithms.als [1.04s] finished epoch 17 (|ΔP|=91.748, |ΔQ|=0.361)
[   INFO] lenskit.algorithms.als [1.10s] finished epoch 18 (|ΔP|=83.159, |ΔQ|=0.341)
[   INFO] lenskit.algorithms.als [1.15s] finished epoch 19 (|ΔP|=91.485, |ΔQ|=0.346)
[   INFO] lenskit.algorithms.als [1.16s] finished training model with 50 features (|P|=2585.461693, |Q|=8.413076)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=50, reg=0.1, w=40) in 1.17s
[   INFO] lenskit.batch._multi generating 675 predictions for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-9v8s8_g5.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 675 predictions for 135 users
[   INFO] lenskit.batch._multi generated predictions in 1.89s
[   INFO] lenskit.batch._multi run 8: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 135 users for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-jlgqn3pq.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=50, reg=0.1, w=40) for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in 1.88s
[   INFO] lenskit.batch._multi generated recommendations in 2.08s
[   INFO] lenskit.batch._multi run 8: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 8: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:1
[   INFO] lenskit.batch._multi starting run 9: Popular on ML-Small:1
[   INFO] lenskit.batch._multi training algorithm Popular on 99329 ratings
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99329 ratings
[   INFO] lenskit.batch._multi trained algorithm Popular in  13ms
[   INFO] lenskit.batch._multi generating recommendations for 135 users for Popular
[   INFO] lenskit.sharing persisting Popular to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-u5seysx_.bpk
[   INFO] binpickle.write pickled 967 bytes with 7 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with Popular for 135 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 135 users in  687ms
[   INFO] lenskit.batch._multi generated recommendations in  757ms
[   INFO] lenskit.batch._multi run 9: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 9: Popular on ML-Small:1
[   INFO] lenskit.batch._multi starting run 10: als.BiasedMF(features=20, regularization=0.1) on ML-Small:2
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=20, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=20, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.542
[   INFO] lenskit.algorithms.basic computed means for 9059 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 35ms] normalizing 671x9059 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 42ms] training biased MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als [ 51ms] finished epoch 0 (|ΔP|=32.182, |ΔQ|=123.970)
[   INFO] lenskit.algorithms.als [ 62ms] finished epoch 1 (|ΔP|=12.051, |ΔQ|=53.112)
[   INFO] lenskit.algorithms.als [ 75ms] finished epoch 2 (|ΔP|=8.789, |ΔQ|=27.769)
[   INFO] lenskit.algorithms.als [ 88ms] finished epoch 3 (|ΔP|=6.172, |ΔQ|=17.540)
[   INFO] lenskit.algorithms.als [ 100ms] finished epoch 4 (|ΔP|=4.598, |ΔQ|=12.869)
[   INFO] lenskit.algorithms.als [ 112ms] finished epoch 5 (|ΔP|=3.569, |ΔQ|=9.991)
[   INFO] lenskit.algorithms.als [ 126ms] finished epoch 6 (|ΔP|=2.877, |ΔQ|=8.118)
[   INFO] lenskit.algorithms.als [ 139ms] finished epoch 7 (|ΔP|=2.393, |ΔQ|=6.813)
[   INFO] lenskit.algorithms.als [ 152ms] finished epoch 8 (|ΔP|=2.042, |ΔQ|=5.843)
[   INFO] lenskit.algorithms.als [ 166ms] finished epoch 9 (|ΔP|=1.779, |ΔQ|=5.092)
[   INFO] lenskit.algorithms.als [ 179ms] finished epoch 10 (|ΔP|=1.574, |ΔQ|=4.490)
[   INFO] lenskit.algorithms.als [ 192ms] finished epoch 11 (|ΔP|=1.408, |ΔQ|=3.997)
[   INFO] lenskit.algorithms.als [ 205ms] finished epoch 12 (|ΔP|=1.272, |ΔQ|=3.588)
[   INFO] lenskit.algorithms.als [ 219ms] finished epoch 13 (|ΔP|=1.157, |ΔQ|=3.247)
[   INFO] lenskit.algorithms.als [ 232ms] finished epoch 14 (|ΔP|=1.060, |ΔQ|=2.959)
[   INFO] lenskit.algorithms.als [ 244ms] finished epoch 15 (|ΔP|=0.977, |ΔQ|=2.713)
[   INFO] lenskit.algorithms.als [ 257ms] finished epoch 16 (|ΔP|=0.903, |ΔQ|=2.499)
[   INFO] lenskit.algorithms.als [ 270ms] finished epoch 17 (|ΔP|=0.838, |ΔQ|=2.310)
[   INFO] lenskit.algorithms.als [ 284ms] finished epoch 18 (|ΔP|=0.779, |ΔQ|=2.141)
[   INFO] lenskit.algorithms.als [ 297ms] finished epoch 19 (|ΔP|=0.726, |ΔQ|=1.991)
[   INFO] lenskit.algorithms.als trained model in  298ms (|P|=29.679664, |Q|=94.403057)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=20, regularization=0.1) in  313ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-1ybb47q3.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.87s
[   INFO] lenskit.batch._multi run 10: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-idr2npgt.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=20, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.89s
[   INFO] lenskit.batch._multi generated recommendations in 2.08s
[   INFO] lenskit.batch._multi run 10: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 10: als.BiasedMF(features=20, regularization=0.1) on ML-Small:2
[   INFO] lenskit.batch._multi starting run 11: als.BiasedMF(features=30, regularization=0.1) on ML-Small:2
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=30, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=30, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.542
[   INFO] lenskit.algorithms.basic computed means for 9059 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 38ms] normalizing 671x9059 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 47ms] training biased MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als [ 63ms] finished epoch 0 (|ΔP|=33.141, |ΔQ|=127.240)
[   INFO] lenskit.algorithms.als [ 80ms] finished epoch 1 (|ΔP|=12.614, |ΔQ|=53.697)
[   INFO] lenskit.algorithms.als [ 97ms] finished epoch 2 (|ΔP|=9.096, |ΔQ|=27.191)
[   INFO] lenskit.algorithms.als [ 115ms] finished epoch 3 (|ΔP|=6.217, |ΔQ|=17.552)
[   INFO] lenskit.algorithms.als [ 134ms] finished epoch 4 (|ΔP|=4.487, |ΔQ|=12.881)
[   INFO] lenskit.algorithms.als [ 153ms] finished epoch 5 (|ΔP|=3.412, |ΔQ|=9.991)
[   INFO] lenskit.algorithms.als [ 173ms] finished epoch 6 (|ΔP|=2.727, |ΔQ|=8.040)
[   INFO] lenskit.algorithms.als [ 193ms] finished epoch 7 (|ΔP|=2.273, |ΔQ|=6.646)
[   INFO] lenskit.algorithms.als [ 213ms] finished epoch 8 (|ΔP|=1.953, |ΔQ|=5.616)
[   INFO] lenskit.algorithms.als [ 231ms] finished epoch 9 (|ΔP|=1.713, |ΔQ|=4.837)
[   INFO] lenskit.algorithms.als [ 250ms] finished epoch 10 (|ΔP|=1.522, |ΔQ|=4.230)
[   INFO] lenskit.algorithms.als [ 269ms] finished epoch 11 (|ΔP|=1.364, |ΔQ|=3.741)
[   INFO] lenskit.algorithms.als [ 286ms] finished epoch 12 (|ΔP|=1.228, |ΔQ|=3.336)
[   INFO] lenskit.algorithms.als [ 305ms] finished epoch 13 (|ΔP|=1.109, |ΔQ|=2.994)
[   INFO] lenskit.algorithms.als [ 323ms] finished epoch 14 (|ΔP|=1.005, |ΔQ|=2.701)
[   INFO] lenskit.algorithms.als [ 342ms] finished epoch 15 (|ΔP|=0.914, |ΔQ|=2.447)
[   INFO] lenskit.algorithms.als [ 360ms] finished epoch 16 (|ΔP|=0.833, |ΔQ|=2.227)
[   INFO] lenskit.algorithms.als [ 379ms] finished epoch 17 (|ΔP|=0.762, |ΔQ|=2.034)
[   INFO] lenskit.algorithms.als [ 398ms] finished epoch 18 (|ΔP|=0.699, |ΔQ|=1.866)
[   INFO] lenskit.algorithms.als [ 416ms] finished epoch 19 (|ΔP|=0.643, |ΔQ|=1.717)
[   INFO] lenskit.algorithms.als trained model in  418ms (|P|=30.783977, |Q|=94.570775)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=30, regularization=0.1) in  432ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-57mcycqu.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.92s
[   INFO] lenskit.batch._multi run 11: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-zj2qmvbp.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=30, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.86s
[   INFO] lenskit.batch._multi generated recommendations in 2.06s
[   INFO] lenskit.batch._multi run 11: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 11: als.BiasedMF(features=30, regularization=0.1) on ML-Small:2
[   INFO] lenskit.batch._multi starting run 12: als.BiasedMF(features=40, regularization=0.1) on ML-Small:2
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=40, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=40, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.542
[   INFO] lenskit.algorithms.basic computed means for 9059 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 41ms] normalizing 671x9059 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 52ms] training biased MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als [ 74ms] finished epoch 0 (|ΔP|=33.550, |ΔQ|=128.060)
[   INFO] lenskit.algorithms.als [ 93ms] finished epoch 1 (|ΔP|=12.835, |ΔQ|=54.282)
[   INFO] lenskit.algorithms.als [ 116ms] finished epoch 2 (|ΔP|=9.471, |ΔQ|=27.924)
[   INFO] lenskit.algorithms.als [ 140ms] finished epoch 3 (|ΔP|=6.239, |ΔQ|=17.265)
[   INFO] lenskit.algorithms.als [ 161ms] finished epoch 4 (|ΔP|=4.385, |ΔQ|=12.487)
[   INFO] lenskit.algorithms.als [ 185ms] finished epoch 5 (|ΔP|=3.309, |ΔQ|=9.559)
[   INFO] lenskit.algorithms.als [ 208ms] finished epoch 6 (|ΔP|=2.624, |ΔQ|=7.616)
[   INFO] lenskit.algorithms.als [ 231ms] finished epoch 7 (|ΔP|=2.152, |ΔQ|=6.267)
[   INFO] lenskit.algorithms.als [ 254ms] finished epoch 8 (|ΔP|=1.811, |ΔQ|=5.294)
[   INFO] lenskit.algorithms.als [ 278ms] finished epoch 9 (|ΔP|=1.556, |ΔQ|=4.565)
[   INFO] lenskit.algorithms.als [ 302ms] finished epoch 10 (|ΔP|=1.360, |ΔQ|=3.997)
[   INFO] lenskit.algorithms.als [ 325ms] finished epoch 11 (|ΔP|=1.206, |ΔQ|=3.539)
[   INFO] lenskit.algorithms.als [ 349ms] finished epoch 12 (|ΔP|=1.081, |ΔQ|=3.159)
[   INFO] lenskit.algorithms.als [ 373ms] finished epoch 13 (|ΔP|=0.978, |ΔQ|=2.838)
[   INFO] lenskit.algorithms.als [ 396ms] finished epoch 14 (|ΔP|=0.891, |ΔQ|=2.565)
[   INFO] lenskit.algorithms.als [ 419ms] finished epoch 15 (|ΔP|=0.818, |ΔQ|=2.331)
[   INFO] lenskit.algorithms.als [ 440ms] finished epoch 16 (|ΔP|=0.754, |ΔQ|=2.129)
[   INFO] lenskit.algorithms.als [ 463ms] finished epoch 17 (|ΔP|=0.699, |ΔQ|=1.954)
[   INFO] lenskit.algorithms.als [ 487ms] finished epoch 18 (|ΔP|=0.651, |ΔQ|=1.803)
[   INFO] lenskit.algorithms.als [ 509ms] finished epoch 19 (|ΔP|=0.608, |ΔQ|=1.671)
[   INFO] lenskit.algorithms.als trained model in  512ms (|P|=31.243407, |Q|=94.662056)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=40, regularization=0.1) in  528ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-81n66289.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.87s
[   INFO] lenskit.batch._multi run 12: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-3zf4d99v.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=40, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.95s
[   INFO] lenskit.batch._multi generated recommendations in 2.15s
[   INFO] lenskit.batch._multi run 12: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 12: als.BiasedMF(features=40, regularization=0.1) on ML-Small:2
[   INFO] lenskit.batch._multi starting run 13: als.BiasedMF(features=50, regularization=0.1) on ML-Small:2
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=50, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=50, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.542
[   INFO] lenskit.algorithms.basic computed means for 9059 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 40ms] normalizing 671x9059 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 52ms] training biased MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als [ 78ms] finished epoch 0 (|ΔP|=34.080, |ΔQ|=128.724)
[   INFO] lenskit.algorithms.als [ 105ms] finished epoch 1 (|ΔP|=12.916, |ΔQ|=55.093)
[   INFO] lenskit.algorithms.als [ 133ms] finished epoch 2 (|ΔP|=9.454, |ΔQ|=27.431)
[   INFO] lenskit.algorithms.als [ 163ms] finished epoch 3 (|ΔP|=6.120, |ΔQ|=17.289)
[   INFO] lenskit.algorithms.als [ 197ms] finished epoch 4 (|ΔP|=4.273, |ΔQ|=12.474)
[   INFO] lenskit.algorithms.als [ 227ms] finished epoch 5 (|ΔP|=3.197, |ΔQ|=9.500)
[   INFO] lenskit.algorithms.als [ 257ms] finished epoch 6 (|ΔP|=2.515, |ΔQ|=7.554)
[   INFO] lenskit.algorithms.als [ 288ms] finished epoch 7 (|ΔP|=2.046, |ΔQ|=6.176)
[   INFO] lenskit.algorithms.als [ 318ms] finished epoch 8 (|ΔP|=1.703, |ΔQ|=5.152)
[   INFO] lenskit.algorithms.als [ 344ms] finished epoch 9 (|ΔP|=1.444, |ΔQ|=4.372)
[   INFO] lenskit.algorithms.als [ 372ms] finished epoch 10 (|ΔP|=1.243, |ΔQ|=3.766)
[   INFO] lenskit.algorithms.als [ 401ms] finished epoch 11 (|ΔP|=1.085, |ΔQ|=3.282)
[   INFO] lenskit.algorithms.als [ 429ms] finished epoch 12 (|ΔP|=0.959, |ΔQ|=2.891)
[   INFO] lenskit.algorithms.als [ 458ms] finished epoch 13 (|ΔP|=0.856, |ΔQ|=2.571)
[   INFO] lenskit.algorithms.als [ 488ms] finished epoch 14 (|ΔP|=0.771, |ΔQ|=2.303)
[   INFO] lenskit.algorithms.als [ 516ms] finished epoch 15 (|ΔP|=0.699, |ΔQ|=2.076)
[   INFO] lenskit.algorithms.als [ 545ms] finished epoch 16 (|ΔP|=0.637, |ΔQ|=1.878)
[   INFO] lenskit.algorithms.als [ 573ms] finished epoch 17 (|ΔP|=0.584, |ΔQ|=1.705)
[   INFO] lenskit.algorithms.als [ 601ms] finished epoch 18 (|ΔP|=0.537, |ΔQ|=1.554)
[   INFO] lenskit.algorithms.als [ 625ms] finished epoch 19 (|ΔP|=0.496, |ΔQ|=1.421)
[   INFO] lenskit.algorithms.als trained model in  628ms (|P|=31.488355, |Q|=94.688959)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=50, regularization=0.1) in  643ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-y7cnds73.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.90s
[   INFO] lenskit.batch._multi run 13: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-gd67chol.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=50, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.91s
[   INFO] lenskit.batch._multi generated recommendations in 2.12s
[   INFO] lenskit.batch._multi run 13: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 13: als.BiasedMF(features=50, regularization=0.1) on ML-Small:2
[   INFO] lenskit.batch._multi starting run 14: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:2
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=20, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=20, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 12ms] training implicit MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9059 items
[   INFO] lenskit.algorithms.als [ 57ms] finished epoch 0 (|ΔP|=3402.517, |ΔQ|=8.849)
[   INFO] lenskit.algorithms.als [ 105ms] finished epoch 1 (|ΔP|=165.373, |ΔQ|=3.576)
[   INFO] lenskit.algorithms.als [ 177ms] finished epoch 2 (|ΔP|=70.845, |ΔQ|=2.407)
[   INFO] lenskit.algorithms.als [ 228ms] finished epoch 3 (|ΔP|=62.977, |ΔQ|=1.824)
[   INFO] lenskit.algorithms.als [ 277ms] finished epoch 4 (|ΔP|=68.344, |ΔQ|=1.582)
[   INFO] lenskit.algorithms.als [ 325ms] finished epoch 5 (|ΔP|=74.716, |ΔQ|=1.407)
[   INFO] lenskit.algorithms.als [ 376ms] finished epoch 6 (|ΔP|=74.762, |ΔQ|=1.202)
[   INFO] lenskit.algorithms.als [ 426ms] finished epoch 7 (|ΔP|=71.862, |ΔQ|=1.026)
[   INFO] lenskit.algorithms.als [ 473ms] finished epoch 8 (|ΔP|=69.738, |ΔQ|=0.895)
[   INFO] lenskit.algorithms.als [ 521ms] finished epoch 9 (|ΔP|=63.080, |ΔQ|=0.803)
[   INFO] lenskit.algorithms.als [ 569ms] finished epoch 10 (|ΔP|=63.476, |ΔQ|=0.725)
[   INFO] lenskit.algorithms.als [ 616ms] finished epoch 11 (|ΔP|=61.933, |ΔQ|=0.663)
[   INFO] lenskit.algorithms.als [ 663ms] finished epoch 12 (|ΔP|=56.981, |ΔQ|=0.601)
[   INFO] lenskit.algorithms.als [ 710ms] finished epoch 13 (|ΔP|=58.126, |ΔQ|=0.581)
[   INFO] lenskit.algorithms.als [ 757ms] finished epoch 14 (|ΔP|=55.184, |ΔQ|=0.543)
[   INFO] lenskit.algorithms.als [ 803ms] finished epoch 15 (|ΔP|=53.067, |ΔQ|=0.506)
[   INFO] lenskit.algorithms.als [ 850ms] finished epoch 16 (|ΔP|=46.104, |ΔQ|=0.461)
[   INFO] lenskit.algorithms.als [ 897ms] finished epoch 17 (|ΔP|=53.481, |ΔQ|=0.470)
[   INFO] lenskit.algorithms.als [ 943ms] finished epoch 18 (|ΔP|=43.898, |ΔQ|=0.417)
[   INFO] lenskit.algorithms.als [ 991ms] finished epoch 19 (|ΔP|=46.695, |ΔQ|=0.420)
[   INFO] lenskit.algorithms.als [ 992ms] finished training model with 20 features (|P|=2693.052181, |Q|=9.918696)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=20, reg=0.1, w=40) in 1.01s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-6g8mziiu.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.89s
[   INFO] lenskit.batch._multi run 14: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-1mftac7d.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=20, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.92s
[   INFO] lenskit.batch._multi generated recommendations in 2.12s
[   INFO] lenskit.batch._multi run 14: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 14: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:2
[   INFO] lenskit.batch._multi starting run 15: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:2
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=30, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=30, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 14ms] training implicit MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9059 items
[   INFO] lenskit.algorithms.als [ 64ms] finished epoch 0 (|ΔP|=3839.187, |ΔQ|=8.261)
[   INFO] lenskit.algorithms.als [ 115ms] finished epoch 1 (|ΔP|=196.361, |ΔQ|=3.208)
[   INFO] lenskit.algorithms.als [ 168ms] finished epoch 2 (|ΔP|=105.465, |ΔQ|=2.146)
[   INFO] lenskit.algorithms.als [ 219ms] finished epoch 3 (|ΔP|=111.411, |ΔQ|=1.681)
[   INFO] lenskit.algorithms.als [ 272ms] finished epoch 4 (|ΔP|=125.129, |ΔQ|=1.373)
[   INFO] lenskit.algorithms.als [ 323ms] finished epoch 5 (|ΔP|=119.156, |ΔQ|=1.098)
[   INFO] lenskit.algorithms.als [ 376ms] finished epoch 6 (|ΔP|=106.082, |ΔQ|=0.924)
[   INFO] lenskit.algorithms.als [ 430ms] finished epoch 7 (|ΔP|=94.524, |ΔQ|=0.806)
[   INFO] lenskit.algorithms.als [ 486ms] finished epoch 8 (|ΔP|=93.629, |ΔQ|=0.724)
[   INFO] lenskit.algorithms.als [ 540ms] finished epoch 9 (|ΔP|=88.710, |ΔQ|=0.644)
[   INFO] lenskit.algorithms.als [ 595ms] finished epoch 10 (|ΔP|=83.786, |ΔQ|=0.609)
[   INFO] lenskit.algorithms.als [ 648ms] finished epoch 11 (|ΔP|=84.301, |ΔQ|=0.561)
[   INFO] lenskit.algorithms.als [ 700ms] finished epoch 12 (|ΔP|=82.129, |ΔQ|=0.531)
[   INFO] lenskit.algorithms.als [ 752ms] finished epoch 13 (|ΔP|=75.127, |ΔQ|=0.490)
[   INFO] lenskit.algorithms.als [ 803ms] finished epoch 14 (|ΔP|=78.422, |ΔQ|=0.483)
[   INFO] lenskit.algorithms.als [ 855ms] finished epoch 15 (|ΔP|=67.931, |ΔQ|=0.437)
[   INFO] lenskit.algorithms.als [ 909ms] finished epoch 16 (|ΔP|=77.571, |ΔQ|=0.448)
[   INFO] lenskit.algorithms.als [ 959ms] finished epoch 17 (|ΔP|=65.900, |ΔQ|=0.408)
[   INFO] lenskit.algorithms.als [1.01s] finished epoch 18 (|ΔP|=76.291, |ΔQ|=0.417)
[   INFO] lenskit.algorithms.als [1.06s] finished epoch 19 (|ΔP|=54.487, |ΔQ|=0.364)
[   INFO] lenskit.algorithms.als [1.07s] finished training model with 30 features (|P|=2769.199197, |Q|=9.173332)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=30, reg=0.1, w=40) in 1.08s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-wujsxbg4.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.91s
[   INFO] lenskit.batch._multi run 15: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-g5rk95rj.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=30, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.97s
[   INFO] lenskit.batch._multi generated recommendations in 2.16s
[   INFO] lenskit.batch._multi run 15: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 15: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:2
[   INFO] lenskit.batch._multi starting run 16: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:2
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=40, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=40, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 16ms] training implicit MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9059 items
[   INFO] lenskit.algorithms.als [ 66ms] finished epoch 0 (|ΔP|=4128.532, |ΔQ|=7.637)
[   INFO] lenskit.algorithms.als [ 117ms] finished epoch 1 (|ΔP|=220.165, |ΔQ|=2.979)
[   INFO] lenskit.algorithms.als [ 170ms] finished epoch 2 (|ΔP|=168.248, |ΔQ|=1.970)
[   INFO] lenskit.algorithms.als [ 225ms] finished epoch 3 (|ΔP|=194.807, |ΔQ|=1.533)
[   INFO] lenskit.algorithms.als [ 280ms] finished epoch 4 (|ΔP|=171.658, |ΔQ|=1.149)
[   INFO] lenskit.algorithms.als [ 334ms] finished epoch 5 (|ΔP|=156.670, |ΔQ|=0.946)
[   INFO] lenskit.algorithms.als [ 388ms] finished epoch 6 (|ΔP|=131.727, |ΔQ|=0.797)
[   INFO] lenskit.algorithms.als [ 442ms] finished epoch 7 (|ΔP|=123.673, |ΔQ|=0.698)
[   INFO] lenskit.algorithms.als [ 496ms] finished epoch 8 (|ΔP|=111.367, |ΔQ|=0.620)
[   INFO] lenskit.algorithms.als [ 551ms] finished epoch 9 (|ΔP|=108.997, |ΔQ|=0.569)
[   INFO] lenskit.algorithms.als [ 602ms] finished epoch 10 (|ΔP|=102.912, |ΔQ|=0.519)
[   INFO] lenskit.algorithms.als [ 655ms] finished epoch 11 (|ΔP|=102.266, |ΔQ|=0.493)
[   INFO] lenskit.algorithms.als [ 707ms] finished epoch 12 (|ΔP|=93.307, |ΔQ|=0.450)
[   INFO] lenskit.algorithms.als [ 759ms] finished epoch 13 (|ΔP|=100.050, |ΔQ|=0.446)
[   INFO] lenskit.algorithms.als [ 813ms] finished epoch 14 (|ΔP|=86.456, |ΔQ|=0.404)
[   INFO] lenskit.algorithms.als [ 865ms] finished epoch 15 (|ΔP|=96.727, |ΔQ|=0.403)
[   INFO] lenskit.algorithms.als [ 918ms] finished epoch 16 (|ΔP|=80.487, |ΔQ|=0.365)
[   INFO] lenskit.algorithms.als [ 972ms] finished epoch 17 (|ΔP|=93.062, |ΔQ|=0.371)
[   INFO] lenskit.algorithms.als [1.03s] finished epoch 18 (|ΔP|=78.584, |ΔQ|=0.337)
[   INFO] lenskit.algorithms.als [1.08s] finished epoch 19 (|ΔP|=95.092, |ΔQ|=0.348)
[   INFO] lenskit.algorithms.als [1.08s] finished training model with 40 features (|P|=2662.006852, |Q|=8.555862)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=40, reg=0.1, w=40) in 1.09s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-yl2nyvs7.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.89s
[   INFO] lenskit.batch._multi run 16: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-zof45ikk.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=40, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.88s
[   INFO] lenskit.batch._multi generated recommendations in 2.08s
[   INFO] lenskit.batch._multi run 16: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 16: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:2
[   INFO] lenskit.batch._multi starting run 17: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:2
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=50, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=50, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 16ms] training implicit MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9059 items
[   INFO] lenskit.algorithms.als [ 69ms] finished epoch 0 (|ΔP|=4303.915, |ΔQ|=7.684)
[   INFO] lenskit.algorithms.als [ 126ms] finished epoch 1 (|ΔP|=223.686, |ΔQ|=2.929)
[   INFO] lenskit.algorithms.als [ 185ms] finished epoch 2 (|ΔP|=191.189, |ΔQ|=1.885)
[   INFO] lenskit.algorithms.als [ 248ms] finished epoch 3 (|ΔP|=221.345, |ΔQ|=1.397)
[   INFO] lenskit.algorithms.als [ 305ms] finished epoch 4 (|ΔP|=195.121, |ΔQ|=1.084)
[   INFO] lenskit.algorithms.als [ 361ms] finished epoch 5 (|ΔP|=172.094, |ΔQ|=0.887)
[   INFO] lenskit.algorithms.als [ 418ms] finished epoch 6 (|ΔP|=146.067, |ΔQ|=0.761)
[   INFO] lenskit.algorithms.als [ 474ms] finished epoch 7 (|ΔP|=137.360, |ΔQ|=0.672)
[   INFO] lenskit.algorithms.als [ 529ms] finished epoch 8 (|ΔP|=133.786, |ΔQ|=0.603)
[   INFO] lenskit.algorithms.als [ 585ms] finished epoch 9 (|ΔP|=113.976, |ΔQ|=0.538)
[   INFO] lenskit.algorithms.als [ 641ms] finished epoch 10 (|ΔP|=113.613, |ΔQ|=0.501)
[   INFO] lenskit.algorithms.als [ 697ms] finished epoch 11 (|ΔP|=107.685, |ΔQ|=0.463)
[   INFO] lenskit.algorithms.als [ 753ms] finished epoch 12 (|ΔP|=98.233, |ΔQ|=0.431)
[   INFO] lenskit.algorithms.als [ 810ms] finished epoch 13 (|ΔP|=106.997, |ΔQ|=0.429)
[   INFO] lenskit.algorithms.als [ 873ms] finished epoch 14 (|ΔP|=92.050, |ΔQ|=0.392)
[   INFO] lenskit.algorithms.als [ 931ms] finished epoch 15 (|ΔP|=105.957, |ΔQ|=0.386)
[   INFO] lenskit.algorithms.als [ 987ms] finished epoch 16 (|ΔP|=90.454, |ΔQ|=0.357)
[   INFO] lenskit.algorithms.als [1.04s] finished epoch 17 (|ΔP|=97.569, |ΔQ|=0.362)
[   INFO] lenskit.algorithms.als [1.10s] finished epoch 18 (|ΔP|=75.906, |ΔQ|=0.325)
[   INFO] lenskit.algorithms.als [1.16s] finished epoch 19 (|ΔP|=100.693, |ΔQ|=0.350)
[   INFO] lenskit.algorithms.als [1.16s] finished training model with 50 features (|P|=2664.711758, |Q|=8.599825)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=50, reg=0.1, w=40) in 1.18s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-_p2cd7en.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.89s
[   INFO] lenskit.batch._multi run 17: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-g5icm38l.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=50, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.93s
[   INFO] lenskit.batch._multi generated recommendations in 2.14s
[   INFO] lenskit.batch._multi run 17: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 17: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:2
[   INFO] lenskit.batch._multi starting run 18: Popular on ML-Small:2
[   INFO] lenskit.batch._multi training algorithm Popular on 99334 ratings
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm Popular in  14ms
[   INFO] lenskit.batch._multi generating recommendations for 134 users for Popular
[   INFO] lenskit.sharing persisting Popular to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-1cf1hnwh.bpk
[   INFO] binpickle.write pickled 967 bytes with 7 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with Popular for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in  739ms
[   INFO] lenskit.batch._multi generated recommendations in  815ms
[   INFO] lenskit.batch._multi run 18: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 18: Popular on ML-Small:2
[   INFO] lenskit.batch._multi starting run 19: als.BiasedMF(features=20, regularization=0.1) on ML-Small:3
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=20, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=20, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9056 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 44ms] normalizing 671x9056 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 54ms] training biased MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als [ 66ms] finished epoch 0 (|ΔP|=32.111, |ΔQ|=124.013)
[   INFO] lenskit.algorithms.als [ 78ms] finished epoch 1 (|ΔP|=12.130, |ΔQ|=51.893)
[   INFO] lenskit.algorithms.als [ 106ms] finished epoch 2 (|ΔP|=8.986, |ΔQ|=26.885)
[   INFO] lenskit.algorithms.als [ 139ms] finished epoch 3 (|ΔP|=6.269, |ΔQ|=17.359)
[   INFO] lenskit.algorithms.als [ 155ms] finished epoch 4 (|ΔP|=4.626, |ΔQ|=12.908)
[   INFO] lenskit.algorithms.als [ 177ms] finished epoch 5 (|ΔP|=3.571, |ΔQ|=10.133)
[   INFO] lenskit.algorithms.als [ 191ms] finished epoch 6 (|ΔP|=2.872, |ΔQ|=8.249)
[   INFO] lenskit.algorithms.als [ 205ms] finished epoch 7 (|ΔP|=2.398, |ΔQ|=6.909)
[   INFO] lenskit.algorithms.als [ 220ms] finished epoch 8 (|ΔP|=2.057, |ΔQ|=5.918)
[   INFO] lenskit.algorithms.als [ 234ms] finished epoch 9 (|ΔP|=1.798, |ΔQ|=5.144)
[   INFO] lenskit.algorithms.als [ 249ms] finished epoch 10 (|ΔP|=1.592, |ΔQ|=4.519)
[   INFO] lenskit.algorithms.als [ 263ms] finished epoch 11 (|ΔP|=1.424, |ΔQ|=4.011)
[   INFO] lenskit.algorithms.als [ 278ms] finished epoch 12 (|ΔP|=1.287, |ΔQ|=3.600)
[   INFO] lenskit.algorithms.als [ 292ms] finished epoch 13 (|ΔP|=1.174, |ΔQ|=3.268)
[   INFO] lenskit.algorithms.als [ 305ms] finished epoch 14 (|ΔP|=1.080, |ΔQ|=2.995)
[   INFO] lenskit.algorithms.als [ 318ms] finished epoch 15 (|ΔP|=1.001, |ΔQ|=2.768)
[   INFO] lenskit.algorithms.als [ 332ms] finished epoch 16 (|ΔP|=0.933, |ΔQ|=2.574)
[   INFO] lenskit.algorithms.als [ 347ms] finished epoch 17 (|ΔP|=0.874, |ΔQ|=2.407)
[   INFO] lenskit.algorithms.als [ 362ms] finished epoch 18 (|ΔP|=0.821, |ΔQ|=2.260)
[   INFO] lenskit.algorithms.als [ 376ms] finished epoch 19 (|ΔP|=0.773, |ΔQ|=2.130)
[   INFO] lenskit.algorithms.als trained model in  377ms (|P|=29.763116, |Q|=94.459451)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=20, regularization=0.1) in  392ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-u92vpizr.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.97s
[   INFO] lenskit.batch._multi run 19: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-cj21w497.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=20, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.91s
[   INFO] lenskit.batch._multi generated recommendations in 2.12s
[   INFO] lenskit.batch._multi run 19: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 19: als.BiasedMF(features=20, regularization=0.1) on ML-Small:3
[   INFO] lenskit.batch._multi starting run 20: als.BiasedMF(features=30, regularization=0.1) on ML-Small:3
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=30, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=30, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9056 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 38ms] normalizing 671x9056 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 47ms] training biased MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als [ 63ms] finished epoch 0 (|ΔP|=33.405, |ΔQ|=127.177)
[   INFO] lenskit.algorithms.als [ 80ms] finished epoch 1 (|ΔP|=12.561, |ΔQ|=53.704)
[   INFO] lenskit.algorithms.als [ 98ms] finished epoch 2 (|ΔP|=9.186, |ΔQ|=27.274)
[   INFO] lenskit.algorithms.als [ 117ms] finished epoch 3 (|ΔP|=6.296, |ΔQ|=17.418)
[   INFO] lenskit.algorithms.als [ 136ms] finished epoch 4 (|ΔP|=4.582, |ΔQ|=12.845)
[   INFO] lenskit.algorithms.als [ 154ms] finished epoch 5 (|ΔP|=3.511, |ΔQ|=9.957)
[   INFO] lenskit.algorithms.als [ 173ms] finished epoch 6 (|ΔP|=2.806, |ΔQ|=7.989)
[   INFO] lenskit.algorithms.als [ 192ms] finished epoch 7 (|ΔP|=2.315, |ΔQ|=6.584)
[   INFO] lenskit.algorithms.als [ 211ms] finished epoch 8 (|ΔP|=1.957, |ΔQ|=5.542)
[   INFO] lenskit.algorithms.als [ 230ms] finished epoch 9 (|ΔP|=1.687, |ΔQ|=4.744)
[   INFO] lenskit.algorithms.als [ 249ms] finished epoch 10 (|ΔP|=1.478, |ΔQ|=4.124)
[   INFO] lenskit.algorithms.als [ 267ms] finished epoch 11 (|ΔP|=1.312, |ΔQ|=3.634)
[   INFO] lenskit.algorithms.als [ 287ms] finished epoch 12 (|ΔP|=1.176, |ΔQ|=3.241)
[   INFO] lenskit.algorithms.als [ 305ms] finished epoch 13 (|ΔP|=1.063, |ΔQ|=2.917)
[   INFO] lenskit.algorithms.als [ 323ms] finished epoch 14 (|ΔP|=0.966, |ΔQ|=2.645)
[   INFO] lenskit.algorithms.als [ 342ms] finished epoch 15 (|ΔP|=0.883, |ΔQ|=2.411)
[   INFO] lenskit.algorithms.als [ 360ms] finished epoch 16 (|ΔP|=0.811, |ΔQ|=2.208)
[   INFO] lenskit.algorithms.als [ 379ms] finished epoch 17 (|ΔP|=0.748, |ΔQ|=2.031)
[   INFO] lenskit.algorithms.als [ 395ms] finished epoch 18 (|ΔP|=0.693, |ΔQ|=1.876)
[   INFO] lenskit.algorithms.als [ 413ms] finished epoch 19 (|ΔP|=0.644, |ΔQ|=1.739)
[   INFO] lenskit.algorithms.als trained model in  414ms (|P|=30.828555, |Q|=94.594339)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=30, regularization=0.1) in  429ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-l7511vib.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.89s
[   INFO] lenskit.batch._multi run 20: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-1ecmmz__.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=30, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.89s
[   INFO] lenskit.batch._multi generated recommendations in 2.09s
[   INFO] lenskit.batch._multi run 20: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 20: als.BiasedMF(features=30, regularization=0.1) on ML-Small:3
[   INFO] lenskit.batch._multi starting run 21: als.BiasedMF(features=40, regularization=0.1) on ML-Small:3
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=40, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=40, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9056 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 37ms] normalizing 671x9056 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 47ms] training biased MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als [ 69ms] finished epoch 0 (|ΔP|=33.989, |ΔQ|=128.492)
[   INFO] lenskit.algorithms.als [ 90ms] finished epoch 1 (|ΔP|=12.852, |ΔQ|=54.033)
[   INFO] lenskit.algorithms.als [ 113ms] finished epoch 2 (|ΔP|=9.362, |ΔQ|=26.681)
[   INFO] lenskit.algorithms.als [ 138ms] finished epoch 3 (|ΔP|=6.198, |ΔQ|=17.205)
[   INFO] lenskit.algorithms.als [ 162ms] finished epoch 4 (|ΔP|=4.391, |ΔQ|=12.593)
[   INFO] lenskit.algorithms.als [ 187ms] finished epoch 5 (|ΔP|=3.300, |ΔQ|=9.644)
[   INFO] lenskit.algorithms.als [ 211ms] finished epoch 6 (|ΔP|=2.605, |ΔQ|=7.686)
[   INFO] lenskit.algorithms.als [ 237ms] finished epoch 7 (|ΔP|=2.133, |ΔQ|=6.310)
[   INFO] lenskit.algorithms.als [ 262ms] finished epoch 8 (|ΔP|=1.791, |ΔQ|=5.293)
[   INFO] lenskit.algorithms.als [ 285ms] finished epoch 9 (|ΔP|=1.532, |ΔQ|=4.517)
[   INFO] lenskit.algorithms.als [ 309ms] finished epoch 10 (|ΔP|=1.329, |ΔQ|=3.911)
[   INFO] lenskit.algorithms.als [ 332ms] finished epoch 11 (|ΔP|=1.168, |ΔQ|=3.426)
[   INFO] lenskit.algorithms.als [ 356ms] finished epoch 12 (|ΔP|=1.037, |ΔQ|=3.032)
[   INFO] lenskit.algorithms.als [ 377ms] finished epoch 13 (|ΔP|=0.930, |ΔQ|=2.710)
[   INFO] lenskit.algorithms.als [ 398ms] finished epoch 14 (|ΔP|=0.842, |ΔQ|=2.444)
[   INFO] lenskit.algorithms.als [ 422ms] finished epoch 15 (|ΔP|=0.767, |ΔQ|=2.216)
[   INFO] lenskit.algorithms.als [ 446ms] finished epoch 16 (|ΔP|=0.702, |ΔQ|=2.017)
[   INFO] lenskit.algorithms.als [ 467ms] finished epoch 17 (|ΔP|=0.645, |ΔQ|=1.841)
[   INFO] lenskit.algorithms.als [ 489ms] finished epoch 18 (|ΔP|=0.594, |ΔQ|=1.684)
[   INFO] lenskit.algorithms.als [ 513ms] finished epoch 19 (|ΔP|=0.549, |ΔQ|=1.545)
[   INFO] lenskit.algorithms.als trained model in  516ms (|P|=31.327223, |Q|=94.660490)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=40, regularization=0.1) in  532ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-q1n41ihm.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.86s
[   INFO] lenskit.batch._multi run 21: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-13pzc4w4.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=40, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.83s
[   INFO] lenskit.batch._multi generated recommendations in 2.03s
[   INFO] lenskit.batch._multi run 21: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 21: als.BiasedMF(features=40, regularization=0.1) on ML-Small:3
[   INFO] lenskit.batch._multi starting run 22: als.BiasedMF(features=50, regularization=0.1) on ML-Small:3
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=50, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=50, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9056 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 40ms] normalizing 671x9056 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 52ms] training biased MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als [ 79ms] finished epoch 0 (|ΔP|=34.317, |ΔQ|=129.361)
[   INFO] lenskit.algorithms.als [ 107ms] finished epoch 1 (|ΔP|=13.053, |ΔQ|=54.269)
[   INFO] lenskit.algorithms.als [ 132ms] finished epoch 2 (|ΔP|=9.375, |ΔQ|=26.523)
[   INFO] lenskit.algorithms.als [ 161ms] finished epoch 3 (|ΔP|=6.160, |ΔQ|=16.806)
[   INFO] lenskit.algorithms.als [ 191ms] finished epoch 4 (|ΔP|=4.415, |ΔQ|=12.262)
[   INFO] lenskit.algorithms.als [ 217ms] finished epoch 5 (|ΔP|=3.351, |ΔQ|=9.409)
[   INFO] lenskit.algorithms.als [ 245ms] finished epoch 6 (|ΔP|=2.635, |ΔQ|=7.482)
[   INFO] lenskit.algorithms.als [ 276ms] finished epoch 7 (|ΔP|=2.127, |ΔQ|=6.115)
[   INFO] lenskit.algorithms.als [ 305ms] finished epoch 8 (|ΔP|=1.757, |ΔQ|=5.107)
[   INFO] lenskit.algorithms.als [ 332ms] finished epoch 9 (|ΔP|=1.480, |ΔQ|=4.337)
[   INFO] lenskit.algorithms.als [ 356ms] finished epoch 10 (|ΔP|=1.268, |ΔQ|=3.731)
[   INFO] lenskit.algorithms.als [ 385ms] finished epoch 11 (|ΔP|=1.103, |ΔQ|=3.246)
[   INFO] lenskit.algorithms.als [ 413ms] finished epoch 12 (|ΔP|=0.972, |ΔQ|=2.851)
[   INFO] lenskit.algorithms.als [ 442ms] finished epoch 13 (|ΔP|=0.865, |ΔQ|=2.524)
[   INFO] lenskit.algorithms.als [ 470ms] finished epoch 14 (|ΔP|=0.777, |ΔQ|=2.251)
[   INFO] lenskit.algorithms.als [ 494ms] finished epoch 15 (|ΔP|=0.703, |ΔQ|=2.022)
[   INFO] lenskit.algorithms.als [ 523ms] finished epoch 16 (|ΔP|=0.641, |ΔQ|=1.826)
[   INFO] lenskit.algorithms.als [ 552ms] finished epoch 17 (|ΔP|=0.588, |ΔQ|=1.656)
[   INFO] lenskit.algorithms.als [ 580ms] finished epoch 18 (|ΔP|=0.541, |ΔQ|=1.508)
[   INFO] lenskit.algorithms.als [ 608ms] finished epoch 19 (|ΔP|=0.501, |ΔQ|=1.379)
[   INFO] lenskit.algorithms.als trained model in  611ms (|P|=31.567742, |Q|=94.697990)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=50, regularization=0.1) in  627ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-svx709_b.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.97s
[   INFO] lenskit.batch._multi run 22: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-e06n3ya6.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=50, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.91s
[   INFO] lenskit.batch._multi generated recommendations in 2.11s
[   INFO] lenskit.batch._multi run 22: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 22: als.BiasedMF(features=50, regularization=0.1) on ML-Small:3
[   INFO] lenskit.batch._multi starting run 23: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:3
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=20, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=20, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 12ms] training implicit MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9056 items
[   INFO] lenskit.algorithms.als [ 62ms] finished epoch 0 (|ΔP|=3357.915, |ΔQ|=8.710)
[   INFO] lenskit.algorithms.als [ 111ms] finished epoch 1 (|ΔP|=181.985, |ΔQ|=3.579)
[   INFO] lenskit.algorithms.als [ 159ms] finished epoch 2 (|ΔP|=73.876, |ΔQ|=2.344)
[   INFO] lenskit.algorithms.als [ 208ms] finished epoch 3 (|ΔP|=68.983, |ΔQ|=1.764)
[   INFO] lenskit.algorithms.als [ 256ms] finished epoch 4 (|ΔP|=84.321, |ΔQ|=1.509)
[   INFO] lenskit.algorithms.als [ 304ms] finished epoch 5 (|ΔP|=81.711, |ΔQ|=1.296)
[   INFO] lenskit.algorithms.als [ 352ms] finished epoch 6 (|ΔP|=81.461, |ΔQ|=1.112)
[   INFO] lenskit.algorithms.als [ 399ms] finished epoch 7 (|ΔP|=71.520, |ΔQ|=0.957)
[   INFO] lenskit.algorithms.als [ 448ms] finished epoch 8 (|ΔP|=75.259, |ΔQ|=0.858)
[   INFO] lenskit.algorithms.als [ 496ms] finished epoch 9 (|ΔP|=65.188, |ΔQ|=0.749)
[   INFO] lenskit.algorithms.als [ 543ms] finished epoch 10 (|ΔP|=61.624, |ΔQ|=0.689)
[   INFO] lenskit.algorithms.als [ 591ms] finished epoch 11 (|ΔP|=65.319, |ΔQ|=0.644)
[   INFO] lenskit.algorithms.als [ 640ms] finished epoch 12 (|ΔP|=56.871, |ΔQ|=0.582)
[   INFO] lenskit.algorithms.als [ 688ms] finished epoch 13 (|ΔP|=56.329, |ΔQ|=0.559)
[   INFO] lenskit.algorithms.als [ 735ms] finished epoch 14 (|ΔP|=65.649, |ΔQ|=0.535)
[   INFO] lenskit.algorithms.als [ 782ms] finished epoch 15 (|ΔP|=52.884, |ΔQ|=0.493)
[   INFO] lenskit.algorithms.als [ 830ms] finished epoch 16 (|ΔP|=50.796, |ΔQ|=0.464)
[   INFO] lenskit.algorithms.als [ 877ms] finished epoch 17 (|ΔP|=49.582, |ΔQ|=0.437)
[   INFO] lenskit.algorithms.als [ 925ms] finished epoch 18 (|ΔP|=52.831, |ΔQ|=0.425)
[   INFO] lenskit.algorithms.als [ 972ms] finished epoch 19 (|ΔP|=51.524, |ΔQ|=0.413)
[   INFO] lenskit.algorithms.als [ 973ms] finished training model with 20 features (|P|=2594.843938, |Q|=9.685295)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=20, reg=0.1, w=40) in  986ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-77147wlo.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.92s
[   INFO] lenskit.batch._multi run 23: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-hhgfvnia.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=20, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.89s
[   INFO] lenskit.batch._multi generated recommendations in 2.10s
[   INFO] lenskit.batch._multi run 23: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 23: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:3
[   INFO] lenskit.batch._multi starting run 24: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:3
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=30, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=30, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 14ms] training implicit MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9056 items
[   INFO] lenskit.algorithms.als [ 67ms] finished epoch 0 (|ΔP|=3788.065, |ΔQ|=8.599)
[   INFO] lenskit.algorithms.als [ 119ms] finished epoch 1 (|ΔP|=184.942, |ΔQ|=3.474)
[   INFO] lenskit.algorithms.als [ 170ms] finished epoch 2 (|ΔP|=99.117, |ΔQ|=2.289)
[   INFO] lenskit.algorithms.als [ 221ms] finished epoch 3 (|ΔP|=100.120, |ΔQ|=1.767)
[   INFO] lenskit.algorithms.als [ 272ms] finished epoch 4 (|ΔP|=107.634, |ΔQ|=1.427)
[   INFO] lenskit.algorithms.als [ 322ms] finished epoch 5 (|ΔP|=102.516, |ΔQ|=1.165)
[   INFO] lenskit.algorithms.als [ 373ms] finished epoch 6 (|ΔP|=100.892, |ΔQ|=0.982)
[   INFO] lenskit.algorithms.als [ 424ms] finished epoch 7 (|ΔP|=83.033, |ΔQ|=0.834)
[   INFO] lenskit.algorithms.als [ 476ms] finished epoch 8 (|ΔP|=83.866, |ΔQ|=0.759)
[   INFO] lenskit.algorithms.als [ 528ms] finished epoch 9 (|ΔP|=68.626, |ΔQ|=0.655)
[   INFO] lenskit.algorithms.als [ 580ms] finished epoch 10 (|ΔP|=82.353, |ΔQ|=0.644)
[   INFO] lenskit.algorithms.als [ 632ms] finished epoch 11 (|ΔP|=69.467, |ΔQ|=0.568)
[   INFO] lenskit.algorithms.als [ 683ms] finished epoch 12 (|ΔP|=79.841, |ΔQ|=0.570)
[   INFO] lenskit.algorithms.als [ 735ms] finished epoch 13 (|ΔP|=64.893, |ΔQ|=0.504)
[   INFO] lenskit.algorithms.als [ 786ms] finished epoch 14 (|ΔP|=105.060, |ΔQ|=0.550)
[   INFO] lenskit.algorithms.als [ 837ms] finished epoch 15 (|ΔP|=57.707, |ΔQ|=0.453)
[   INFO] lenskit.algorithms.als [ 888ms] finished epoch 16 (|ΔP|=78.045, |ΔQ|=0.488)
[   INFO] lenskit.algorithms.als [ 940ms] finished epoch 17 (|ΔP|=50.216, |ΔQ|=0.406)
[   INFO] lenskit.algorithms.als [ 992ms] finished epoch 18 (|ΔP|=82.333, |ΔQ|=0.452)
[   INFO] lenskit.algorithms.als [1.05s] finished epoch 19 (|ΔP|=48.702, |ΔQ|=0.375)
[   INFO] lenskit.algorithms.als [1.05s] finished training model with 30 features (|P|=2806.043472, |Q|=9.975942)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=30, reg=0.1, w=40) in 1.07s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-8mv4_f9p.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.92s
[   INFO] lenskit.batch._multi run 24: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-cghi931b.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=30, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.85s
[   INFO] lenskit.batch._multi generated recommendations in 2.05s
[   INFO] lenskit.batch._multi run 24: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 24: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:3
[   INFO] lenskit.batch._multi starting run 25: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:3
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=40, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=40, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 15ms] training implicit MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9056 items
[   INFO] lenskit.algorithms.als [ 66ms] finished epoch 0 (|ΔP|=4092.606, |ΔQ|=7.808)
[   INFO] lenskit.algorithms.als [ 117ms] finished epoch 1 (|ΔP|=223.575, |ΔQ|=3.012)
[   INFO] lenskit.algorithms.als [ 170ms] finished epoch 2 (|ΔP|=148.022, |ΔQ|=2.026)
[   INFO] lenskit.algorithms.als [ 223ms] finished epoch 3 (|ΔP|=178.204, |ΔQ|=1.554)
[   INFO] lenskit.algorithms.als [ 276ms] finished epoch 4 (|ΔP|=169.362, |ΔQ|=1.191)
[   INFO] lenskit.algorithms.als [ 329ms] finished epoch 5 (|ΔP|=146.490, |ΔQ|=0.962)
[   INFO] lenskit.algorithms.als [ 382ms] finished epoch 6 (|ΔP|=140.628, |ΔQ|=0.823)
[   INFO] lenskit.algorithms.als [ 435ms] finished epoch 7 (|ΔP|=121.566, |ΔQ|=0.711)
[   INFO] lenskit.algorithms.als [ 487ms] finished epoch 8 (|ΔP|=105.469, |ΔQ|=0.625)
[   INFO] lenskit.algorithms.als [ 541ms] finished epoch 9 (|ΔP|=106.792, |ΔQ|=0.587)
[   INFO] lenskit.algorithms.als [ 595ms] finished epoch 10 (|ΔP|=105.799, |ΔQ|=0.540)
[   INFO] lenskit.algorithms.als [ 648ms] finished epoch 11 (|ΔP|=109.223, |ΔQ|=0.522)
[   INFO] lenskit.algorithms.als [ 701ms] finished epoch 12 (|ΔP|=97.034, |ΔQ|=0.469)
[   INFO] lenskit.algorithms.als [ 754ms] finished epoch 13 (|ΔP|=99.933, |ΔQ|=0.467)
[   INFO] lenskit.algorithms.als [ 806ms] finished epoch 14 (|ΔP|=86.103, |ΔQ|=0.418)
[   INFO] lenskit.algorithms.als [ 860ms] finished epoch 15 (|ΔP|=108.292, |ΔQ|=0.436)
[   INFO] lenskit.algorithms.als [ 913ms] finished epoch 16 (|ΔP|=72.599, |ΔQ|=0.370)
[   INFO] lenskit.algorithms.als [ 970ms] finished epoch 17 (|ΔP|=98.976, |ΔQ|=0.396)
[   INFO] lenskit.algorithms.als [1.02s] finished epoch 18 (|ΔP|=73.355, |ΔQ|=0.346)
[   INFO] lenskit.algorithms.als [1.08s] finished epoch 19 (|ΔP|=98.873, |ΔQ|=0.390)
[   INFO] lenskit.algorithms.als [1.08s] finished training model with 40 features (|P|=2658.712288, |Q|=8.539329)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=40, reg=0.1, w=40) in 1.09s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-nyem282k.bpk
[   INFO] binpickle.write pickled 1192 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.91s
[   INFO] lenskit.batch._multi run 25: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-nxcu4s0t.bpk
[   INFO] binpickle.write pickled 1192 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=40, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.84s
[   INFO] lenskit.batch._multi generated recommendations in 2.05s
[   INFO] lenskit.batch._multi run 25: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 25: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:3
[   INFO] lenskit.batch._multi starting run 26: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:3
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=50, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=50, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 18ms] training implicit MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9056 items
[   INFO] lenskit.algorithms.als [ 74ms] finished epoch 0 (|ΔP|=4311.068, |ΔQ|=7.565)
[   INFO] lenskit.algorithms.als [ 128ms] finished epoch 1 (|ΔP|=231.260, |ΔQ|=2.910)
[   INFO] lenskit.algorithms.als [ 183ms] finished epoch 2 (|ΔP|=200.886, |ΔQ|=1.865)
[   INFO] lenskit.algorithms.als [ 238ms] finished epoch 3 (|ΔP|=232.445, |ΔQ|=1.397)
[   INFO] lenskit.algorithms.als [ 292ms] finished epoch 4 (|ΔP|=198.132, |ΔQ|=1.074)
[   INFO] lenskit.algorithms.als [ 347ms] finished epoch 5 (|ΔP|=169.233, |ΔQ|=0.858)
[   INFO] lenskit.algorithms.als [ 404ms] finished epoch 6 (|ΔP|=150.187, |ΔQ|=0.742)
[   INFO] lenskit.algorithms.als [ 459ms] finished epoch 7 (|ΔP|=139.323, |ΔQ|=0.651)
[   INFO] lenskit.algorithms.als [ 514ms] finished epoch 8 (|ΔP|=140.788, |ΔQ|=0.593)
[   INFO] lenskit.algorithms.als [ 569ms] finished epoch 9 (|ΔP|=120.490, |ΔQ|=0.533)
[   INFO] lenskit.algorithms.als [ 624ms] finished epoch 10 (|ΔP|=115.518, |ΔQ|=0.491)
[   INFO] lenskit.algorithms.als [ 679ms] finished epoch 11 (|ΔP|=112.176, |ΔQ|=0.460)
[   INFO] lenskit.algorithms.als [ 734ms] finished epoch 12 (|ΔP|=107.829, |ΔQ|=0.432)
[   INFO] lenskit.algorithms.als [ 789ms] finished epoch 13 (|ΔP|=107.469, |ΔQ|=0.410)
[   INFO] lenskit.algorithms.als [ 867ms] finished epoch 14 (|ΔP|=97.138, |ΔQ|=0.395)
[   INFO] lenskit.algorithms.als [ 939ms] finished epoch 15 (|ΔP|=104.980, |ΔQ|=0.384)
[   INFO] lenskit.algorithms.als [ 999ms] finished epoch 16 (|ΔP|=87.470, |ΔQ|=0.352)
[   INFO] lenskit.algorithms.als [1.05s] finished epoch 17 (|ΔP|=102.041, |ΔQ|=0.357)
[   INFO] lenskit.algorithms.als [1.11s] finished epoch 18 (|ΔP|=88.463, |ΔQ|=0.337)
[   INFO] lenskit.algorithms.als [1.16s] finished epoch 19 (|ΔP|=89.352, |ΔQ|=0.331)
[   INFO] lenskit.algorithms.als [1.17s] finished training model with 50 features (|P|=2621.603224, |Q|=8.521143)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=50, reg=0.1, w=40) in 1.18s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-b30jtcwd.bpk
[   INFO] binpickle.write pickled 1192 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.99s
[   INFO] lenskit.batch._multi run 26: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-0d04mu3w.bpk
[   INFO] binpickle.write pickled 1192 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=50, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 2.05s
[   INFO] lenskit.batch._multi generated recommendations in 2.28s
[   INFO] lenskit.batch._multi run 26: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 26: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:3
[   INFO] lenskit.batch._multi starting run 27: Popular on ML-Small:3
[   INFO] lenskit.batch._multi training algorithm Popular on 99334 ratings
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm Popular in  14ms
[   INFO] lenskit.batch._multi generating recommendations for 134 users for Popular
[   INFO] lenskit.sharing persisting Popular to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-642blguk.bpk
[   INFO] binpickle.write pickled 967 bytes with 7 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with Popular for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in  772ms
[   INFO] lenskit.batch._multi generated recommendations in  846ms
[   INFO] lenskit.batch._multi run 27: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 27: Popular on ML-Small:3
[   INFO] lenskit.batch._multi starting run 28: als.BiasedMF(features=20, regularization=0.1) on ML-Small:4
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=20, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=20, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9059 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 37ms] normalizing 671x9059 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 48ms] training biased MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als [ 63ms] finished epoch 0 (|ΔP|=32.464, |ΔQ|=124.546)
[   INFO] lenskit.algorithms.als [ 75ms] finished epoch 1 (|ΔP|=12.140, |ΔQ|=52.024)
[   INFO] lenskit.algorithms.als [ 87ms] finished epoch 2 (|ΔP|=8.842, |ΔQ|=26.757)
[   INFO] lenskit.algorithms.als [ 100ms] finished epoch 3 (|ΔP|=6.100, |ΔQ|=17.223)
[   INFO] lenskit.algorithms.als [ 113ms] finished epoch 4 (|ΔP|=4.500, |ΔQ|=12.806)
[   INFO] lenskit.algorithms.als [ 126ms] finished epoch 5 (|ΔP|=3.538, |ΔQ|=10.055)
[   INFO] lenskit.algorithms.als [ 140ms] finished epoch 6 (|ΔP|=2.924, |ΔQ|=8.199)
[   INFO] lenskit.algorithms.als [ 155ms] finished epoch 7 (|ΔP|=2.485, |ΔQ|=6.874)
[   INFO] lenskit.algorithms.als [ 167ms] finished epoch 8 (|ΔP|=2.141, |ΔQ|=5.877)
[   INFO] lenskit.algorithms.als [ 181ms] finished epoch 9 (|ΔP|=1.858, |ΔQ|=5.099)
[   INFO] lenskit.algorithms.als [ 194ms] finished epoch 10 (|ΔP|=1.623, |ΔQ|=4.479)
[   INFO] lenskit.algorithms.als [ 207ms] finished epoch 11 (|ΔP|=1.429, |ΔQ|=3.978)
[   INFO] lenskit.algorithms.als [ 222ms] finished epoch 12 (|ΔP|=1.270, |ΔQ|=3.568)
[   INFO] lenskit.algorithms.als [ 236ms] finished epoch 13 (|ΔP|=1.140, |ΔQ|=3.229)
[   INFO] lenskit.algorithms.als [ 250ms] finished epoch 14 (|ΔP|=1.034, |ΔQ|=2.948)
[   INFO] lenskit.algorithms.als [ 265ms] finished epoch 15 (|ΔP|=0.946, |ΔQ|=2.712)
[   INFO] lenskit.algorithms.als [ 279ms] finished epoch 16 (|ΔP|=0.873, |ΔQ|=2.514)
[   INFO] lenskit.algorithms.als [ 292ms] finished epoch 17 (|ΔP|=0.811, |ΔQ|=2.344)
[   INFO] lenskit.algorithms.als [ 306ms] finished epoch 18 (|ΔP|=0.758, |ΔQ|=2.198)
[   INFO] lenskit.algorithms.als [ 320ms] finished epoch 19 (|ΔP|=0.712, |ΔQ|=2.068)
[   INFO] lenskit.algorithms.als trained model in  322ms (|P|=29.735833, |Q|=94.434018)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=20, regularization=0.1) in  337ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-0pfw3yto.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 2.04s
[   INFO] lenskit.batch._multi run 28: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-hvfd9b1a.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=20, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.89s
[   INFO] lenskit.batch._multi generated recommendations in 2.10s
[   INFO] lenskit.batch._multi run 28: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 28: als.BiasedMF(features=20, regularization=0.1) on ML-Small:4
[   INFO] lenskit.batch._multi starting run 29: als.BiasedMF(features=30, regularization=0.1) on ML-Small:4
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=30, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=30, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9059 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 36ms] normalizing 671x9059 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 45ms] training biased MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als [ 62ms] finished epoch 0 (|ΔP|=33.149, |ΔQ|=126.683)
[   INFO] lenskit.algorithms.als [ 80ms] finished epoch 1 (|ΔP|=12.531, |ΔQ|=54.027)
[   INFO] lenskit.algorithms.als [ 98ms] finished epoch 2 (|ΔP|=9.214, |ΔQ|=27.636)
[   INFO] lenskit.algorithms.als [ 117ms] finished epoch 3 (|ΔP|=6.197, |ΔQ|=17.192)
[   INFO] lenskit.algorithms.als [ 135ms] finished epoch 4 (|ΔP|=4.445, |ΔQ|=12.560)
[   INFO] lenskit.algorithms.als [ 153ms] finished epoch 5 (|ΔP|=3.410, |ΔQ|=9.730)
[   INFO] lenskit.algorithms.als [ 172ms] finished epoch 6 (|ΔP|=2.751, |ΔQ|=7.807)
[   INFO] lenskit.algorithms.als [ 191ms] finished epoch 7 (|ΔP|=2.293, |ΔQ|=6.434)
[   INFO] lenskit.algorithms.als [ 208ms] finished epoch 8 (|ΔP|=1.952, |ΔQ|=5.428)
[   INFO] lenskit.algorithms.als [ 227ms] finished epoch 9 (|ΔP|=1.689, |ΔQ|=4.677)
[   INFO] lenskit.algorithms.als [ 246ms] finished epoch 10 (|ΔP|=1.482, |ΔQ|=4.101)
[   INFO] lenskit.algorithms.als [ 264ms] finished epoch 11 (|ΔP|=1.317, |ΔQ|=3.647)
[   INFO] lenskit.algorithms.als [ 283ms] finished epoch 12 (|ΔP|=1.184, |ΔQ|=3.277)
[   INFO] lenskit.algorithms.als [ 302ms] finished epoch 13 (|ΔP|=1.074, |ΔQ|=2.966)
[   INFO] lenskit.algorithms.als [ 320ms] finished epoch 14 (|ΔP|=0.981, |ΔQ|=2.696)
[   INFO] lenskit.algorithms.als [ 339ms] finished epoch 15 (|ΔP|=0.900, |ΔQ|=2.459)
[   INFO] lenskit.algorithms.als [ 357ms] finished epoch 16 (|ΔP|=0.829, |ΔQ|=2.249)
[   INFO] lenskit.algorithms.als [ 375ms] finished epoch 17 (|ΔP|=0.765, |ΔQ|=2.065)
[   INFO] lenskit.algorithms.als [ 394ms] finished epoch 18 (|ΔP|=0.709, |ΔQ|=1.903)
[   INFO] lenskit.algorithms.als [ 411ms] finished epoch 19 (|ΔP|=0.659, |ΔQ|=1.762)
[   INFO] lenskit.algorithms.als trained model in  412ms (|P|=30.778758, |Q|=94.562917)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=30, regularization=0.1) in  427ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-dtd2xilv.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.93s
[   INFO] lenskit.batch._multi run 29: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-6kb_y4oo.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=30, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.84s
[   INFO] lenskit.batch._multi generated recommendations in 2.07s
[   INFO] lenskit.batch._multi run 29: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 29: als.BiasedMF(features=30, regularization=0.1) on ML-Small:4
[   INFO] lenskit.batch._multi starting run 30: als.BiasedMF(features=40, regularization=0.1) on ML-Small:4
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=40, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=40, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9059 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 41ms] normalizing 671x9059 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 52ms] training biased MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als [ 73ms] finished epoch 0 (|ΔP|=33.861, |ΔQ|=128.130)
[   INFO] lenskit.algorithms.als [ 96ms] finished epoch 1 (|ΔP|=12.860, |ΔQ|=54.030)
[   INFO] lenskit.algorithms.als [ 120ms] finished epoch 2 (|ΔP|=9.463, |ΔQ|=27.509)
[   INFO] lenskit.algorithms.als [ 142ms] finished epoch 3 (|ΔP|=6.230, |ΔQ|=17.281)
[   INFO] lenskit.algorithms.als [ 166ms] finished epoch 4 (|ΔP|=4.419, |ΔQ|=12.543)
[   INFO] lenskit.algorithms.als [ 190ms] finished epoch 5 (|ΔP|=3.367, |ΔQ|=9.627)
[   INFO] lenskit.algorithms.als [ 215ms] finished epoch 6 (|ΔP|=2.688, |ΔQ|=7.703)
[   INFO] lenskit.algorithms.als [ 236ms] finished epoch 7 (|ΔP|=2.212, |ΔQ|=6.337)
[   INFO] lenskit.algorithms.als [ 259ms] finished epoch 8 (|ΔP|=1.857, |ΔQ|=5.311)
[   INFO] lenskit.algorithms.als [ 283ms] finished epoch 9 (|ΔP|=1.583, |ΔQ|=4.515)
[   INFO] lenskit.algorithms.als [ 307ms] finished epoch 10 (|ΔP|=1.367, |ΔQ|=3.886)
[   INFO] lenskit.algorithms.als [ 332ms] finished epoch 11 (|ΔP|=1.193, |ΔQ|=3.385)
[   INFO] lenskit.algorithms.als [ 359ms] finished epoch 12 (|ΔP|=1.052, |ΔQ|=2.984)
[   INFO] lenskit.algorithms.als [ 384ms] finished epoch 13 (|ΔP|=0.936, |ΔQ|=2.659)
[   INFO] lenskit.algorithms.als [ 408ms] finished epoch 14 (|ΔP|=0.840, |ΔQ|=2.392)
[   INFO] lenskit.algorithms.als [ 431ms] finished epoch 15 (|ΔP|=0.760, |ΔQ|=2.168)
[   INFO] lenskit.algorithms.als [ 455ms] finished epoch 16 (|ΔP|=0.693, |ΔQ|=1.977)
[   INFO] lenskit.algorithms.als [ 478ms] finished epoch 17 (|ΔP|=0.635, |ΔQ|=1.811)
[   INFO] lenskit.algorithms.als [ 501ms] finished epoch 18 (|ΔP|=0.586, |ΔQ|=1.666)
[   INFO] lenskit.algorithms.als [ 525ms] finished epoch 19 (|ΔP|=0.542, |ΔQ|=1.538)
[   INFO] lenskit.algorithms.als trained model in  528ms (|P|=31.278303, |Q|=94.632456)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=40, regularization=0.1) in  544ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-004ltxjh.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.96s
[   INFO] lenskit.batch._multi run 30: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-i1xhpqu0.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=40, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.97s
[   INFO] lenskit.batch._multi generated recommendations in 2.19s
[   INFO] lenskit.batch._multi run 30: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 30: als.BiasedMF(features=40, regularization=0.1) on ML-Small:4
[   INFO] lenskit.batch._multi starting run 31: als.BiasedMF(features=50, regularization=0.1) on ML-Small:4
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=50, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=50, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9059 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 40ms] normalizing 671x9059 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 54ms] training biased MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als [ 81ms] finished epoch 0 (|ΔP|=34.181, |ΔQ|=128.832)
[   INFO] lenskit.algorithms.als [ 111ms] finished epoch 1 (|ΔP|=13.037, |ΔQ|=54.526)
[   INFO] lenskit.algorithms.als [ 135ms] finished epoch 2 (|ΔP|=9.395, |ΔQ|=27.100)
[   INFO] lenskit.algorithms.als [ 165ms] finished epoch 3 (|ΔP|=6.127, |ΔQ|=17.173)
[   INFO] lenskit.algorithms.als [ 194ms] finished epoch 4 (|ΔP|=4.313, |ΔQ|=12.515)
[   INFO] lenskit.algorithms.als [ 219ms] finished epoch 5 (|ΔP|=3.226, |ΔQ|=9.601)
[   INFO] lenskit.algorithms.als [ 249ms] finished epoch 6 (|ΔP|=2.527, |ΔQ|=7.652)
[   INFO] lenskit.algorithms.als [ 279ms] finished epoch 7 (|ΔP|=2.046, |ΔQ|=6.273)
[   INFO] lenskit.algorithms.als [ 305ms] finished epoch 8 (|ΔP|=1.696, |ΔQ|=5.243)
[   INFO] lenskit.algorithms.als [ 333ms] finished epoch 9 (|ΔP|=1.431, |ΔQ|=4.436)
[   INFO] lenskit.algorithms.als [ 362ms] finished epoch 10 (|ΔP|=1.225, |ΔQ|=3.791)
[   INFO] lenskit.algorithms.als [ 390ms] finished epoch 11 (|ΔP|=1.063, |ΔQ|=3.272)
[   INFO] lenskit.algorithms.als [ 419ms] finished epoch 12 (|ΔP|=0.934, |ΔQ|=2.855)
[   INFO] lenskit.algorithms.als [ 448ms] finished epoch 13 (|ΔP|=0.829, |ΔQ|=2.519)
[   INFO] lenskit.algorithms.als [ 477ms] finished epoch 14 (|ΔP|=0.743, |ΔQ|=2.242)
[   INFO] lenskit.algorithms.als [ 508ms] finished epoch 15 (|ΔP|=0.672, |ΔQ|=2.008)
[   INFO] lenskit.algorithms.als [ 538ms] finished epoch 16 (|ΔP|=0.613, |ΔQ|=1.810)
[   INFO] lenskit.algorithms.als [ 567ms] finished epoch 17 (|ΔP|=0.563, |ΔQ|=1.643)
[   INFO] lenskit.algorithms.als [ 597ms] finished epoch 18 (|ΔP|=0.520, |ΔQ|=1.501)
[   INFO] lenskit.algorithms.als [ 627ms] finished epoch 19 (|ΔP|=0.482, |ΔQ|=1.379)
[   INFO] lenskit.algorithms.als trained model in  629ms (|P|=31.510081, |Q|=94.653882)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=50, regularization=0.1) in  646ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-2z8g23xf.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.92s
[   INFO] lenskit.batch._multi run 31: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-zuoxkutj.bpk
[   INFO] binpickle.write pickled 1340 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=50, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 2.02s
[   INFO] lenskit.batch._multi generated recommendations in 2.23s
[   INFO] lenskit.batch._multi run 31: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 31: als.BiasedMF(features=50, regularization=0.1) on ML-Small:4
[   INFO] lenskit.batch._multi starting run 32: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:4
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=20, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=20, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 13ms] training implicit MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9059 items
[   INFO] lenskit.algorithms.als [ 61ms] finished epoch 0 (|ΔP|=3384.911, |ΔQ|=9.139)
[   INFO] lenskit.algorithms.als [ 111ms] finished epoch 1 (|ΔP|=179.309, |ΔQ|=3.723)
[   INFO] lenskit.algorithms.als [ 160ms] finished epoch 2 (|ΔP|=66.444, |ΔQ|=2.406)
[   INFO] lenskit.algorithms.als [ 208ms] finished epoch 3 (|ΔP|=59.216, |ΔQ|=1.878)
[   INFO] lenskit.algorithms.als [ 257ms] finished epoch 4 (|ΔP|=65.790, |ΔQ|=1.630)
[   INFO] lenskit.algorithms.als [ 308ms] finished epoch 5 (|ΔP|=70.422, |ΔQ|=1.398)
[   INFO] lenskit.algorithms.als [ 357ms] finished epoch 6 (|ΔP|=70.259, |ΔQ|=1.177)
[   INFO] lenskit.algorithms.als [ 409ms] finished epoch 7 (|ΔP|=70.535, |ΔQ|=1.028)
[   INFO] lenskit.algorithms.als [ 458ms] finished epoch 8 (|ΔP|=63.489, |ΔQ|=0.895)
[   INFO] lenskit.algorithms.als [ 509ms] finished epoch 9 (|ΔP|=65.777, |ΔQ|=0.813)
[   INFO] lenskit.algorithms.als [ 558ms] finished epoch 10 (|ΔP|=55.906, |ΔQ|=0.721)
[   INFO] lenskit.algorithms.als [ 606ms] finished epoch 11 (|ΔP|=60.511, |ΔQ|=0.676)
[   INFO] lenskit.algorithms.als [ 655ms] finished epoch 12 (|ΔP|=56.574, |ΔQ|=0.624)
[   INFO] lenskit.algorithms.als [ 703ms] finished epoch 13 (|ΔP|=55.349, |ΔQ|=0.595)
[   INFO] lenskit.algorithms.als [ 751ms] finished epoch 14 (|ΔP|=53.960, |ΔQ|=0.561)
[   INFO] lenskit.algorithms.als [ 799ms] finished epoch 15 (|ΔP|=50.375, |ΔQ|=0.523)
[   INFO] lenskit.algorithms.als [ 848ms] finished epoch 16 (|ΔP|=51.098, |ΔQ|=0.500)
[   INFO] lenskit.algorithms.als [ 896ms] finished epoch 17 (|ΔP|=45.104, |ΔQ|=0.469)
[   INFO] lenskit.algorithms.als [ 946ms] finished epoch 18 (|ΔP|=54.495, |ΔQ|=0.487)
[   INFO] lenskit.algorithms.als [ 994ms] finished epoch 19 (|ΔP|=40.602, |ΔQ|=0.418)
[   INFO] lenskit.algorithms.als [ 995ms] finished training model with 20 features (|P|=2711.510296, |Q|=9.958338)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=20, reg=0.1, w=40) in 1.01s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-7vhwwpbu.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.98s
[   INFO] lenskit.batch._multi run 32: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-6l1dh9sw.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=20, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.93s
[   INFO] lenskit.batch._multi generated recommendations in 2.14s
[   INFO] lenskit.batch._multi run 32: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 32: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:4
[   INFO] lenskit.batch._multi starting run 33: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:4
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=30, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=30, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 14ms] training implicit MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9059 items
[   INFO] lenskit.algorithms.als [ 62ms] finished epoch 0 (|ΔP|=3805.819, |ΔQ|=8.315)
[   INFO] lenskit.algorithms.als [ 113ms] finished epoch 1 (|ΔP|=200.755, |ΔQ|=3.272)
[   INFO] lenskit.algorithms.als [ 164ms] finished epoch 2 (|ΔP|=107.821, |ΔQ|=2.245)
[   INFO] lenskit.algorithms.als [ 216ms] finished epoch 3 (|ΔP|=114.832, |ΔQ|=1.754)
[   INFO] lenskit.algorithms.als [ 269ms] finished epoch 4 (|ΔP|=128.287, |ΔQ|=1.433)
[   INFO] lenskit.algorithms.als [ 322ms] finished epoch 5 (|ΔP|=128.031, |ΔQ|=1.156)
[   INFO] lenskit.algorithms.als [ 377ms] finished epoch 6 (|ΔP|=106.760, |ΔQ|=0.965)
[   INFO] lenskit.algorithms.als [ 428ms] finished epoch 7 (|ΔP|=98.827, |ΔQ|=0.829)
[   INFO] lenskit.algorithms.als [ 482ms] finished epoch 8 (|ΔP|=98.387, |ΔQ|=0.756)
[   INFO] lenskit.algorithms.als [ 535ms] finished epoch 9 (|ΔP|=83.666, |ΔQ|=0.657)
[   INFO] lenskit.algorithms.als [ 587ms] finished epoch 10 (|ΔP|=94.149, |ΔQ|=0.624)
[   INFO] lenskit.algorithms.als [ 641ms] finished epoch 11 (|ΔP|=78.380, |ΔQ|=0.558)
[   INFO] lenskit.algorithms.als [ 693ms] finished epoch 12 (|ΔP|=88.744, |ΔQ|=0.549)
[   INFO] lenskit.algorithms.als [ 746ms] finished epoch 13 (|ΔP|=75.823, |ΔQ|=0.490)
[   INFO] lenskit.algorithms.als [ 799ms] finished epoch 14 (|ΔP|=89.571, |ΔQ|=0.492)
[   INFO] lenskit.algorithms.als [ 851ms] finished epoch 15 (|ΔP|=67.314, |ΔQ|=0.442)
[   INFO] lenskit.algorithms.als [ 905ms] finished epoch 16 (|ΔP|=82.458, |ΔQ|=0.451)
[   INFO] lenskit.algorithms.als [ 961ms] finished epoch 17 (|ΔP|=58.195, |ΔQ|=0.392)
[   INFO] lenskit.algorithms.als [1.01s] finished epoch 18 (|ΔP|=73.681, |ΔQ|=0.400)
[   INFO] lenskit.algorithms.als [1.07s] finished epoch 19 (|ΔP|=59.646, |ΔQ|=0.362)
[   INFO] lenskit.algorithms.als [1.07s] finished training model with 30 features (|P|=2689.675737, |Q|=9.299979)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=30, reg=0.1, w=40) in 1.08s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-bu3034s6.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.92s
[   INFO] lenskit.batch._multi run 33: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-_48rx_al.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=30, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.80s
[   INFO] lenskit.batch._multi generated recommendations in 2.00s
[   INFO] lenskit.batch._multi run 33: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 33: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:4
[   INFO] lenskit.batch._multi starting run 34: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:4
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=40, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=40, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 16ms] training implicit MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9059 items
[   INFO] lenskit.algorithms.als [ 68ms] finished epoch 0 (|ΔP|=4111.694, |ΔQ|=7.796)
[   INFO] lenskit.algorithms.als [ 118ms] finished epoch 1 (|ΔP|=212.261, |ΔQ|=3.058)
[   INFO] lenskit.algorithms.als [ 172ms] finished epoch 2 (|ΔP|=156.573, |ΔQ|=1.997)
[   INFO] lenskit.algorithms.als [ 225ms] finished epoch 3 (|ΔP|=174.744, |ΔQ|=1.525)
[   INFO] lenskit.algorithms.als [ 278ms] finished epoch 4 (|ΔP|=170.051, |ΔQ|=1.188)
[   INFO] lenskit.algorithms.als [ 330ms] finished epoch 5 (|ΔP|=136.223, |ΔQ|=0.939)
[   INFO] lenskit.algorithms.als [ 383ms] finished epoch 6 (|ΔP|=129.221, |ΔQ|=0.807)
[   INFO] lenskit.algorithms.als [ 438ms] finished epoch 7 (|ΔP|=123.600, |ΔQ|=0.702)
[   INFO] lenskit.algorithms.als [ 515ms] finished epoch 8 (|ΔP|=110.418, |ΔQ|=0.627)
[   INFO] lenskit.algorithms.als [ 577ms] finished epoch 9 (|ΔP|=111.233, |ΔQ|=0.573)
[   INFO] lenskit.algorithms.als [ 631ms] finished epoch 10 (|ΔP|=102.674, |ΔQ|=0.536)
[   INFO] lenskit.algorithms.als [ 685ms] finished epoch 11 (|ΔP|=98.389, |ΔQ|=0.492)
[   INFO] lenskit.algorithms.als [ 738ms] finished epoch 12 (|ΔP|=101.211, |ΔQ|=0.467)
[   INFO] lenskit.algorithms.als [ 791ms] finished epoch 13 (|ΔP|=91.078, |ΔQ|=0.434)
[   INFO] lenskit.algorithms.als [ 844ms] finished epoch 14 (|ΔP|=109.555, |ΔQ|=0.439)
[   INFO] lenskit.algorithms.als [ 904ms] finished epoch 15 (|ΔP|=79.916, |ΔQ|=0.393)
[   INFO] lenskit.algorithms.als [ 957ms] finished epoch 16 (|ΔP|=83.805, |ΔQ|=0.386)
[   INFO] lenskit.algorithms.als [1.01s] finished epoch 17 (|ΔP|=74.346, |ΔQ|=0.356)
[   INFO] lenskit.algorithms.als [1.06s] finished epoch 18 (|ΔP|=79.450, |ΔQ|=0.353)
[   INFO] lenskit.algorithms.als [1.12s] finished epoch 19 (|ΔP|=79.956, |ΔQ|=0.349)
[   INFO] lenskit.algorithms.als [1.12s] finished training model with 40 features (|P|=2721.630024, |Q|=8.660680)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=40, reg=0.1, w=40) in 1.13s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-t8h6jxg8.bpk
[   INFO] binpickle.write pickled 1192 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.91s
[   INFO] lenskit.batch._multi run 34: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-wf1qx0ub.bpk
[   INFO] binpickle.write pickled 1192 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=40, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.82s
[   INFO] lenskit.batch._multi generated recommendations in 2.02s
[   INFO] lenskit.batch._multi run 34: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 34: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:4
[   INFO] lenskit.batch._multi starting run 35: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:4
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=50, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=50, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 18ms] training implicit MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9059 items
[   INFO] lenskit.algorithms.als [ 72ms] finished epoch 0 (|ΔP|=4322.730, |ΔQ|=6.940)
[   INFO] lenskit.algorithms.als [ 127ms] finished epoch 1 (|ΔP|=266.656, |ΔQ|=2.623)
[   INFO] lenskit.algorithms.als [ 182ms] finished epoch 2 (|ΔP|=274.084, |ΔQ|=1.779)
[   INFO] lenskit.algorithms.als [ 237ms] finished epoch 3 (|ΔP|=286.518, |ΔQ|=1.320)
[   INFO] lenskit.algorithms.als [ 291ms] finished epoch 4 (|ΔP|=242.929, |ΔQ|=1.032)
[   INFO] lenskit.algorithms.als [ 347ms] finished epoch 5 (|ΔP|=205.454, |ΔQ|=0.849)
[   INFO] lenskit.algorithms.als [ 401ms] finished epoch 6 (|ΔP|=182.811, |ΔQ|=0.727)
[   INFO] lenskit.algorithms.als [ 455ms] finished epoch 7 (|ΔP|=163.238, |ΔQ|=0.633)
[   INFO] lenskit.algorithms.als [ 511ms] finished epoch 8 (|ΔP|=150.520, |ΔQ|=0.576)
[   INFO] lenskit.algorithms.als [ 567ms] finished epoch 9 (|ΔP|=138.748, |ΔQ|=0.519)
[   INFO] lenskit.algorithms.als [ 622ms] finished epoch 10 (|ΔP|=142.712, |ΔQ|=0.487)
[   INFO] lenskit.algorithms.als [ 678ms] finished epoch 11 (|ΔP|=117.773, |ΔQ|=0.437)
[   INFO] lenskit.algorithms.als [ 734ms] finished epoch 12 (|ΔP|=127.544, |ΔQ|=0.430)
[   INFO] lenskit.algorithms.als [ 793ms] finished epoch 13 (|ΔP|=119.131, |ΔQ|=0.399)
[   INFO] lenskit.algorithms.als [ 852ms] finished epoch 14 (|ΔP|=115.869, |ΔQ|=0.389)
[   INFO] lenskit.algorithms.als [ 908ms] finished epoch 15 (|ΔP|=104.002, |ΔQ|=0.360)
[   INFO] lenskit.algorithms.als [ 963ms] finished epoch 16 (|ΔP|=110.334, |ΔQ|=0.357)
[   INFO] lenskit.algorithms.als [1.02s] finished epoch 17 (|ΔP|=87.453, |ΔQ|=0.324)
[   INFO] lenskit.algorithms.als [1.07s] finished epoch 18 (|ΔP|=99.526, |ΔQ|=0.329)
[   INFO] lenskit.algorithms.als [1.13s] finished epoch 19 (|ΔP|=77.154, |ΔQ|=0.301)
[   INFO] lenskit.algorithms.als [1.13s] finished training model with 50 features (|P|=2311.787688, |Q|=7.720594)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=50, reg=0.1, w=40) in 1.15s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-mu4rvk48.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.87s
[   INFO] lenskit.batch._multi run 35: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-pdzx_jzk.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=50, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.89s
[   INFO] lenskit.batch._multi generated recommendations in 2.10s
[   INFO] lenskit.batch._multi run 35: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 35: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:4
[   INFO] lenskit.batch._multi starting run 36: Popular on ML-Small:4
[   INFO] lenskit.batch._multi training algorithm Popular on 99334 ratings
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm Popular in  12ms
[   INFO] lenskit.batch._multi generating recommendations for 134 users for Popular
[   INFO] lenskit.sharing persisting Popular to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-aqkdsrai.bpk
[   INFO] binpickle.write pickled 967 bytes with 7 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with Popular for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in  740ms
[   INFO] lenskit.batch._multi generated recommendations in  813ms
[   INFO] lenskit.batch._multi run 36: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 36: Popular on ML-Small:4
[   INFO] lenskit.batch._multi starting run 37: als.BiasedMF(features=20, regularization=0.1) on ML-Small:5
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=20, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=20, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9063 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 38ms] normalizing 671x9063 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 46ms] training biased MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als [ 58ms] finished epoch 0 (|ΔP|=32.552, |ΔQ|=123.296)
[   INFO] lenskit.algorithms.als [ 71ms] finished epoch 1 (|ΔP|=12.025, |ΔQ|=53.195)
[   INFO] lenskit.algorithms.als [ 83ms] finished epoch 2 (|ΔP|=8.976, |ΔQ|=28.077)
[   INFO] lenskit.algorithms.als [ 99ms] finished epoch 3 (|ΔP|=6.167, |ΔQ|=17.713)
[   INFO] lenskit.algorithms.als [ 115ms] finished epoch 4 (|ΔP|=4.541, |ΔQ|=12.977)
[   INFO] lenskit.algorithms.als [ 129ms] finished epoch 5 (|ΔP|=3.523, |ΔQ|=10.003)
[   INFO] lenskit.algorithms.als [ 141ms] finished epoch 6 (|ΔP|=2.835, |ΔQ|=8.034)
[   INFO] lenskit.algorithms.als [ 154ms] finished epoch 7 (|ΔP|=2.357, |ΔQ|=6.679)
[   INFO] lenskit.algorithms.als [ 167ms] finished epoch 8 (|ΔP|=2.012, |ΔQ|=5.693)
[   INFO] lenskit.algorithms.als [ 182ms] finished epoch 9 (|ΔP|=1.750, |ΔQ|=4.935)
[   INFO] lenskit.algorithms.als [ 196ms] finished epoch 10 (|ΔP|=1.544, |ΔQ|=4.330)
[   INFO] lenskit.algorithms.als [ 209ms] finished epoch 11 (|ΔP|=1.379, |ΔQ|=3.843)
[   INFO] lenskit.algorithms.als [ 222ms] finished epoch 12 (|ΔP|=1.245, |ΔQ|=3.446)
[   INFO] lenskit.algorithms.als [ 235ms] finished epoch 13 (|ΔP|=1.133, |ΔQ|=3.117)
[   INFO] lenskit.algorithms.als [ 249ms] finished epoch 14 (|ΔP|=1.039, |ΔQ|=2.840)
[   INFO] lenskit.algorithms.als [ 262ms] finished epoch 15 (|ΔP|=0.958, |ΔQ|=2.605)
[   INFO] lenskit.algorithms.als [ 276ms] finished epoch 16 (|ΔP|=0.887, |ΔQ|=2.403)
[   INFO] lenskit.algorithms.als [ 289ms] finished epoch 17 (|ΔP|=0.825, |ΔQ|=2.228)
[   INFO] lenskit.algorithms.als [ 302ms] finished epoch 18 (|ΔP|=0.770, |ΔQ|=2.076)
[   INFO] lenskit.algorithms.als [ 314ms] finished epoch 19 (|ΔP|=0.721, |ΔQ|=1.944)
[   INFO] lenskit.algorithms.als trained model in  316ms (|P|=29.778578, |Q|=94.413827)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=20, regularization=0.1) in  332ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-lw9xrplj.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.95s
[   INFO] lenskit.batch._multi run 37: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=20, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=20, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-mslljrms.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=20, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.91s
[   INFO] lenskit.batch._multi generated recommendations in 2.11s
[   INFO] lenskit.batch._multi run 37: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 37: als.BiasedMF(features=20, regularization=0.1) on ML-Small:5
[   INFO] lenskit.batch._multi starting run 38: als.BiasedMF(features=30, regularization=0.1) on ML-Small:5
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=30, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=30, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9063 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 38ms] normalizing 671x9063 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 48ms] training biased MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als [ 64ms] finished epoch 0 (|ΔP|=33.353, |ΔQ|=127.417)
[   INFO] lenskit.algorithms.als [ 80ms] finished epoch 1 (|ΔP|=12.688, |ΔQ|=53.269)
[   INFO] lenskit.algorithms.als [ 98ms] finished epoch 2 (|ΔP|=9.149, |ΔQ|=26.745)
[   INFO] lenskit.algorithms.als [ 117ms] finished epoch 3 (|ΔP|=6.246, |ΔQ|=17.242)
[   INFO] lenskit.algorithms.als [ 135ms] finished epoch 4 (|ΔP|=4.520, |ΔQ|=12.615)
[   INFO] lenskit.algorithms.als [ 154ms] finished epoch 5 (|ΔP|=3.464, |ΔQ|=9.722)
[   INFO] lenskit.algorithms.als [ 173ms] finished epoch 6 (|ΔP|=2.781, |ΔQ|=7.810)
[   INFO] lenskit.algorithms.als [ 192ms] finished epoch 7 (|ΔP|=2.307, |ΔQ|=6.468)
[   INFO] lenskit.algorithms.als [ 211ms] finished epoch 8 (|ΔP|=1.956, |ΔQ|=5.478)
[   INFO] lenskit.algorithms.als [ 229ms] finished epoch 9 (|ΔP|=1.684, |ΔQ|=4.724)
[   INFO] lenskit.algorithms.als [ 246ms] finished epoch 10 (|ΔP|=1.467, |ΔQ|=4.134)
[   INFO] lenskit.algorithms.als [ 263ms] finished epoch 11 (|ΔP|=1.294, |ΔQ|=3.658)
[   INFO] lenskit.algorithms.als [ 282ms] finished epoch 12 (|ΔP|=1.156, |ΔQ|=3.266)
[   INFO] lenskit.algorithms.als [ 301ms] finished epoch 13 (|ΔP|=1.043, |ΔQ|=2.941)
[   INFO] lenskit.algorithms.als [ 320ms] finished epoch 14 (|ΔP|=0.950, |ΔQ|=2.669)
[   INFO] lenskit.algorithms.als [ 339ms] finished epoch 15 (|ΔP|=0.872, |ΔQ|=2.439)
[   INFO] lenskit.algorithms.als [ 360ms] finished epoch 16 (|ΔP|=0.804, |ΔQ|=2.241)
[   INFO] lenskit.algorithms.als [ 379ms] finished epoch 17 (|ΔP|=0.745, |ΔQ|=2.070)
[   INFO] lenskit.algorithms.als [ 398ms] finished epoch 18 (|ΔP|=0.694, |ΔQ|=1.920)
[   INFO] lenskit.algorithms.als [ 417ms] finished epoch 19 (|ΔP|=0.649, |ΔQ|=1.788)
[   INFO] lenskit.algorithms.als trained model in  418ms (|P|=30.777912, |Q|=94.579922)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=30, regularization=0.1) in  433ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-m9get0dy.bpk
[   INFO] binpickle.write pickled 1338 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.92s
[   INFO] lenskit.batch._multi run 38: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=30, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=30, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-a4it8oq3.bpk
[   INFO] binpickle.write pickled 1338 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=30, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.91s
[   INFO] lenskit.batch._multi generated recommendations in 2.11s
[   INFO] lenskit.batch._multi run 38: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 38: als.BiasedMF(features=30, regularization=0.1) on ML-Small:5
[   INFO] lenskit.batch._multi starting run 39: als.BiasedMF(features=40, regularization=0.1) on ML-Small:5
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=40, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=40, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9063 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 39ms] normalizing 671x9063 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 51ms] training biased MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als [ 72ms] finished epoch 0 (|ΔP|=34.240, |ΔQ|=128.070)
[   INFO] lenskit.algorithms.als [ 94ms] finished epoch 1 (|ΔP|=12.770, |ΔQ|=54.373)
[   INFO] lenskit.algorithms.als [ 117ms] finished epoch 2 (|ΔP|=9.374, |ΔQ|=27.261)
[   INFO] lenskit.algorithms.als [ 141ms] finished epoch 3 (|ΔP|=6.214, |ΔQ|=17.317)
[   INFO] lenskit.algorithms.als [ 163ms] finished epoch 4 (|ΔP|=4.430, |ΔQ|=12.690)
[   INFO] lenskit.algorithms.als [ 186ms] finished epoch 5 (|ΔP|=3.361, |ΔQ|=9.755)
[   INFO] lenskit.algorithms.als [ 211ms] finished epoch 6 (|ΔP|=2.664, |ΔQ|=7.759)
[   INFO] lenskit.algorithms.als [ 235ms] finished epoch 7 (|ΔP|=2.182, |ΔQ|=6.350)
[   INFO] lenskit.algorithms.als [ 257ms] finished epoch 8 (|ΔP|=1.832, |ΔQ|=5.325)
[   INFO] lenskit.algorithms.als [ 282ms] finished epoch 9 (|ΔP|=1.568, |ΔQ|=4.549)
[   INFO] lenskit.algorithms.als [ 307ms] finished epoch 10 (|ΔP|=1.362, |ΔQ|=3.939)
[   INFO] lenskit.algorithms.als [ 332ms] finished epoch 11 (|ΔP|=1.197, |ΔQ|=3.448)
[   INFO] lenskit.algorithms.als [ 355ms] finished epoch 12 (|ΔP|=1.063, |ΔQ|=3.048)
[   INFO] lenskit.algorithms.als [ 379ms] finished epoch 13 (|ΔP|=0.952, |ΔQ|=2.720)
[   INFO] lenskit.algorithms.als [ 402ms] finished epoch 14 (|ΔP|=0.859, |ΔQ|=2.445)
[   INFO] lenskit.algorithms.als [ 426ms] finished epoch 15 (|ΔP|=0.780, |ΔQ|=2.211)
[   INFO] lenskit.algorithms.als [ 450ms] finished epoch 16 (|ΔP|=0.712, |ΔQ|=2.011)
[   INFO] lenskit.algorithms.als [ 474ms] finished epoch 17 (|ΔP|=0.654, |ΔQ|=1.838)
[   INFO] lenskit.algorithms.als [ 498ms] finished epoch 18 (|ΔP|=0.603, |ΔQ|=1.690)
[   INFO] lenskit.algorithms.als [ 522ms] finished epoch 19 (|ΔP|=0.559, |ΔQ|=1.563)
[   INFO] lenskit.algorithms.als trained model in  525ms (|P|=31.319241, |Q|=94.628291)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=40, regularization=0.1) in  542ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-oin4b17q.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.89s
[   INFO] lenskit.batch._multi run 39: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=40, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=40, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-9a6a1d1_.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=40, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.92s
[   INFO] lenskit.batch._multi generated recommendations in 2.12s
[   INFO] lenskit.batch._multi run 39: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 39: als.BiasedMF(features=40, regularization=0.1) on ML-Small:5
[   INFO] lenskit.batch._multi starting run 40: als.BiasedMF(features=50, regularization=0.1) on ML-Small:5
[   INFO] lenskit.batch._multi adapting als.BiasedMF(features=50, regularization=0.1) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.BiasedMF(features=50, regularization=0.1) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 0ms] fitting bias model
[   INFO] lenskit.algorithms.basic building bias model for 99334 ratings
[   INFO] lenskit.algorithms.basic global mean: 3.543
[   INFO] lenskit.algorithms.basic computed means for 9063 items
[   INFO] lenskit.algorithms.basic computed means for 671 users
[   INFO] lenskit.algorithms.als [ 37ms] normalizing 671x9063 matrix (99334 nnz)
[   INFO] lenskit.algorithms.als [ 49ms] training biased MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als [ 77ms] finished epoch 0 (|ΔP|=34.147, |ΔQ|=128.724)
[   INFO] lenskit.algorithms.als [ 106ms] finished epoch 1 (|ΔP|=13.005, |ΔQ|=54.757)
[   INFO] lenskit.algorithms.als [ 134ms] finished epoch 2 (|ΔP|=9.463, |ΔQ|=27.389)
[   INFO] lenskit.algorithms.als [ 163ms] finished epoch 3 (|ΔP|=6.203, |ΔQ|=17.411)
[   INFO] lenskit.algorithms.als [ 189ms] finished epoch 4 (|ΔP|=4.376, |ΔQ|=12.652)
[   INFO] lenskit.algorithms.als [ 218ms] finished epoch 5 (|ΔP|=3.266, |ΔQ|=9.623)
[   INFO] lenskit.algorithms.als [ 246ms] finished epoch 6 (|ΔP|=2.551, |ΔQ|=7.618)
[   INFO] lenskit.algorithms.als [ 274ms] finished epoch 7 (|ΔP|=2.065, |ΔQ|=6.236)
[   INFO] lenskit.algorithms.als [ 304ms] finished epoch 8 (|ΔP|=1.718, |ΔQ|=5.231)
[   INFO] lenskit.algorithms.als [ 334ms] finished epoch 9 (|ΔP|=1.458, |ΔQ|=4.463)
[   INFO] lenskit.algorithms.als [ 365ms] finished epoch 10 (|ΔP|=1.256, |ΔQ|=3.847)
[   INFO] lenskit.algorithms.als [ 397ms] finished epoch 11 (|ΔP|=1.095, |ΔQ|=3.335)
[   INFO] lenskit.algorithms.als [ 428ms] finished epoch 12 (|ΔP|=0.964, |ΔQ|=2.908)
[   INFO] lenskit.algorithms.als [ 457ms] finished epoch 13 (|ΔP|=0.855, |ΔQ|=2.555)
[   INFO] lenskit.algorithms.als [ 487ms] finished epoch 14 (|ΔP|=0.763, |ΔQ|=2.264)
[   INFO] lenskit.algorithms.als [ 516ms] finished epoch 15 (|ΔP|=0.686, |ΔQ|=2.020)
[   INFO] lenskit.algorithms.als [ 544ms] finished epoch 16 (|ΔP|=0.620, |ΔQ|=1.814)
[   INFO] lenskit.algorithms.als [ 570ms] finished epoch 17 (|ΔP|=0.564, |ΔQ|=1.639)
[   INFO] lenskit.algorithms.als [ 599ms] finished epoch 18 (|ΔP|=0.515, |ΔQ|=1.491)
[   INFO] lenskit.algorithms.als [ 628ms] finished epoch 19 (|ΔP|=0.473, |ΔQ|=1.364)
[   INFO] lenskit.algorithms.als trained model in  631ms (|P|=31.554301, |Q|=94.674680)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.BiasedMF(features=50, regularization=0.1) in  648ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-3h1q8sef.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.91s
[   INFO] lenskit.batch._multi run 40: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.BiasedMF(features=50, regularization=0.1)
[   INFO] lenskit.sharing persisting TopN/als.BiasedMF(features=50, regularization=0.1) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-2nsbi2er.bpk
[   INFO] binpickle.write pickled 1339 bytes with 10 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.BiasedMF(features=50, regularization=0.1) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.92s
[   INFO] lenskit.batch._multi generated recommendations in 2.13s
[   INFO] lenskit.batch._multi run 40: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 40: als.BiasedMF(features=50, regularization=0.1) on ML-Small:5
[   INFO] lenskit.batch._multi starting run 41: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:5
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=20, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=20, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 13ms] training implicit MF model with ALS for 20 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9063 items
[   INFO] lenskit.algorithms.als [ 58ms] finished epoch 0 (|ΔP|=3355.018, |ΔQ|=8.951)
[   INFO] lenskit.algorithms.als [ 106ms] finished epoch 1 (|ΔP|=175.236, |ΔQ|=3.678)
[   INFO] lenskit.algorithms.als [ 154ms] finished epoch 2 (|ΔP|=67.529, |ΔQ|=2.475)
[   INFO] lenskit.algorithms.als [ 202ms] finished epoch 3 (|ΔP|=60.492, |ΔQ|=1.862)
[   INFO] lenskit.algorithms.als [ 251ms] finished epoch 4 (|ΔP|=65.468, |ΔQ|=1.589)
[   INFO] lenskit.algorithms.als [ 299ms] finished epoch 5 (|ΔP|=69.249, |ΔQ|=1.380)
[   INFO] lenskit.algorithms.als [ 347ms] finished epoch 6 (|ΔP|=70.908, |ΔQ|=1.193)
[   INFO] lenskit.algorithms.als [ 395ms] finished epoch 7 (|ΔP|=69.268, |ΔQ|=1.017)
[   INFO] lenskit.algorithms.als [ 442ms] finished epoch 8 (|ΔP|=61.565, |ΔQ|=0.900)
[   INFO] lenskit.algorithms.als [ 489ms] finished epoch 9 (|ΔP|=62.983, |ΔQ|=0.815)
[   INFO] lenskit.algorithms.als [ 537ms] finished epoch 10 (|ΔP|=56.960, |ΔQ|=0.724)
[   INFO] lenskit.algorithms.als [ 585ms] finished epoch 11 (|ΔP|=64.989, |ΔQ|=0.700)
[   INFO] lenskit.algorithms.als [ 635ms] finished epoch 12 (|ΔP|=53.611, |ΔQ|=0.623)
[   INFO] lenskit.algorithms.als [ 683ms] finished epoch 13 (|ΔP|=55.810, |ΔQ|=0.595)
[   INFO] lenskit.algorithms.als [ 732ms] finished epoch 14 (|ΔP|=53.119, |ΔQ|=0.543)
[   INFO] lenskit.algorithms.als [ 779ms] finished epoch 15 (|ΔP|=66.903, |ΔQ|=0.558)
[   INFO] lenskit.algorithms.als [ 827ms] finished epoch 16 (|ΔP|=51.305, |ΔQ|=0.498)
[   INFO] lenskit.algorithms.als [ 874ms] finished epoch 17 (|ΔP|=73.329, |ΔQ|=0.542)
[   INFO] lenskit.algorithms.als [ 922ms] finished epoch 18 (|ΔP|=41.683, |ΔQ|=0.445)
[   INFO] lenskit.algorithms.als [ 969ms] finished epoch 19 (|ΔP|=59.176, |ΔQ|=0.492)
[   INFO] lenskit.algorithms.als [ 971ms] finished training model with 20 features (|P|=2642.705467, |Q|=9.916332)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=20, reg=0.1, w=40) in  986ms
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-ls6b4qve.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.93s
[   INFO] lenskit.batch._multi run 41: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=20, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=20, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-u2z7d478.bpk
[   INFO] binpickle.write pickled 1194 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=20, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.73s
[   INFO] lenskit.batch._multi generated recommendations in 1.92s
[   INFO] lenskit.batch._multi run 41: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 41: als.ImplicitMF(features=20, reg=0.1, w=40) on ML-Small:5
[   INFO] lenskit.batch._multi starting run 42: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:5
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=30, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=30, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 14ms] training implicit MF model with ALS for 30 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9063 items
[   INFO] lenskit.algorithms.als [ 64ms] finished epoch 0 (|ΔP|=3811.909, |ΔQ|=8.193)
[   INFO] lenskit.algorithms.als [ 115ms] finished epoch 1 (|ΔP|=198.052, |ΔQ|=3.263)
[   INFO] lenskit.algorithms.als [ 166ms] finished epoch 2 (|ΔP|=109.306, |ΔQ|=2.168)
[   INFO] lenskit.algorithms.als [ 218ms] finished epoch 3 (|ΔP|=117.540, |ΔQ|=1.687)
[   INFO] lenskit.algorithms.als [ 269ms] finished epoch 4 (|ΔP|=124.541, |ΔQ|=1.354)
[   INFO] lenskit.algorithms.als [ 322ms] finished epoch 5 (|ΔP|=124.002, |ΔQ|=1.106)
[   INFO] lenskit.algorithms.als [ 374ms] finished epoch 6 (|ΔP|=97.685, |ΔQ|=0.913)
[   INFO] lenskit.algorithms.als [ 425ms] finished epoch 7 (|ΔP|=96.469, |ΔQ|=0.812)
[   INFO] lenskit.algorithms.als [ 477ms] finished epoch 8 (|ΔP|=89.784, |ΔQ|=0.718)
[   INFO] lenskit.algorithms.als [ 529ms] finished epoch 9 (|ΔP|=84.360, |ΔQ|=0.654)
[   INFO] lenskit.algorithms.als [ 580ms] finished epoch 10 (|ΔP|=80.133, |ΔQ|=0.595)
[   INFO] lenskit.algorithms.als [ 632ms] finished epoch 11 (|ΔP|=78.652, |ΔQ|=0.564)
[   INFO] lenskit.algorithms.als [ 685ms] finished epoch 12 (|ΔP|=79.025, |ΔQ|=0.524)
[   INFO] lenskit.algorithms.als [ 736ms] finished epoch 13 (|ΔP|=86.098, |ΔQ|=0.520)
[   INFO] lenskit.algorithms.als [ 790ms] finished epoch 14 (|ΔP|=66.418, |ΔQ|=0.472)
[   INFO] lenskit.algorithms.als [ 842ms] finished epoch 15 (|ΔP|=88.431, |ΔQ|=0.500)
[   INFO] lenskit.algorithms.als [ 894ms] finished epoch 16 (|ΔP|=59.289, |ΔQ|=0.423)
[   INFO] lenskit.algorithms.als [ 945ms] finished epoch 17 (|ΔP|=80.883, |ΔQ|=0.450)
[   INFO] lenskit.algorithms.als [ 997ms] finished epoch 18 (|ΔP|=53.785, |ΔQ|=0.384)
[   INFO] lenskit.algorithms.als [1.05s] finished epoch 19 (|ΔP|=93.311, |ΔQ|=0.437)
[   INFO] lenskit.algorithms.als [1.05s] finished training model with 30 features (|P|=2702.199180, |Q|=9.126627)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=30, reg=0.1, w=40) in 1.06s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-ztz6xd_w.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.88s
[   INFO] lenskit.batch._multi run 42: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=30, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=30, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-z3on2twx.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=30, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.82s
[   INFO] lenskit.batch._multi generated recommendations in 2.02s
[   INFO] lenskit.batch._multi run 42: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 42: als.ImplicitMF(features=30, reg=0.1, w=40) on ML-Small:5
[   INFO] lenskit.batch._multi starting run 43: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:5
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=40, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=40, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 15ms] training implicit MF model with ALS for 40 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9063 items
[   INFO] lenskit.algorithms.als [ 66ms] finished epoch 0 (|ΔP|=4088.491, |ΔQ|=8.081)
[   INFO] lenskit.algorithms.als [ 118ms] finished epoch 1 (|ΔP|=204.760, |ΔQ|=3.054)
[   INFO] lenskit.algorithms.als [ 170ms] finished epoch 2 (|ΔP|=137.835, |ΔQ|=1.979)
[   INFO] lenskit.algorithms.als [ 223ms] finished epoch 3 (|ΔP|=171.879, |ΔQ|=1.517)
[   INFO] lenskit.algorithms.als [ 275ms] finished epoch 4 (|ΔP|=159.322, |ΔQ|=1.184)
[   INFO] lenskit.algorithms.als [ 328ms] finished epoch 5 (|ΔP|=134.153, |ΔQ|=0.943)
[   INFO] lenskit.algorithms.als [ 381ms] finished epoch 6 (|ΔP|=122.469, |ΔQ|=0.800)
[   INFO] lenskit.algorithms.als [ 434ms] finished epoch 7 (|ΔP|=110.212, |ΔQ|=0.694)
[   INFO] lenskit.algorithms.als [ 487ms] finished epoch 8 (|ΔP|=112.739, |ΔQ|=0.630)
[   INFO] lenskit.algorithms.als [ 541ms] finished epoch 9 (|ΔP|=95.057, |ΔQ|=0.557)
[   INFO] lenskit.algorithms.als [ 595ms] finished epoch 10 (|ΔP|=99.849, |ΔQ|=0.519)
[   INFO] lenskit.algorithms.als [ 649ms] finished epoch 11 (|ΔP|=92.813, |ΔQ|=0.477)
[   INFO] lenskit.algorithms.als [ 704ms] finished epoch 12 (|ΔP|=90.571, |ΔQ|=0.451)
[   INFO] lenskit.algorithms.als [ 760ms] finished epoch 13 (|ΔP|=82.357, |ΔQ|=0.416)
[   INFO] lenskit.algorithms.als [ 827ms] finished epoch 14 (|ΔP|=87.906, |ΔQ|=0.410)
[   INFO] lenskit.algorithms.als [ 884ms] finished epoch 15 (|ΔP|=80.260, |ΔQ|=0.375)
[   INFO] lenskit.algorithms.als [ 936ms] finished epoch 16 (|ΔP|=79.077, |ΔQ|=0.366)
[   INFO] lenskit.algorithms.als [ 990ms] finished epoch 17 (|ΔP|=87.854, |ΔQ|=0.361)
[   INFO] lenskit.algorithms.als [1.04s] finished epoch 18 (|ΔP|=74.162, |ΔQ|=0.332)
[   INFO] lenskit.algorithms.als [1.10s] finished epoch 19 (|ΔP|=68.013, |ΔQ|=0.316)
[   INFO] lenskit.algorithms.als [1.10s] finished training model with 40 features (|P|=2798.864673, |Q|=8.851169)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=40, reg=0.1, w=40) in 1.12s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-2dx388rr.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.89s
[   INFO] lenskit.batch._multi run 43: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=40, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=40, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-rn022yb5.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=40, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.86s
[   INFO] lenskit.batch._multi generated recommendations in 2.06s
[   INFO] lenskit.batch._multi run 43: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 43: als.ImplicitMF(features=40, reg=0.1, w=40) on ML-Small:5
[   INFO] lenskit.batch._multi starting run 44: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:5
[   INFO] lenskit.batch._multi adapting als.ImplicitMF(features=50, reg=0.1, w=40) into a recommender
[   INFO] lenskit.batch._multi training algorithm als.ImplicitMF(features=50, reg=0.1, w=40) on 99334 ratings
[   INFO] lenskit.algorithms.als [ 17ms] training implicit MF model with ALS for 50 features
[   INFO] lenskit.algorithms.als have 99334 observations for 671 users and 9063 items
[   INFO] lenskit.algorithms.als [ 69ms] finished epoch 0 (|ΔP|=4314.240, |ΔQ|=7.350)
[   INFO] lenskit.algorithms.als [ 123ms] finished epoch 1 (|ΔP|=243.305, |ΔQ|=2.852)
[   INFO] lenskit.algorithms.als [ 181ms] finished epoch 2 (|ΔP|=218.755, |ΔQ|=1.829)
[   INFO] lenskit.algorithms.als [ 236ms] finished epoch 3 (|ΔP|=241.981, |ΔQ|=1.347)
[   INFO] lenskit.algorithms.als [ 291ms] finished epoch 4 (|ΔP|=213.236, |ΔQ|=1.029)
[   INFO] lenskit.algorithms.als [ 346ms] finished epoch 5 (|ΔP|=170.938, |ΔQ|=0.827)
[   INFO] lenskit.algorithms.als [ 403ms] finished epoch 6 (|ΔP|=151.324, |ΔQ|=0.705)
[   INFO] lenskit.algorithms.als [ 458ms] finished epoch 7 (|ΔP|=146.010, |ΔQ|=0.623)
[   INFO] lenskit.algorithms.als [ 513ms] finished epoch 8 (|ΔP|=126.886, |ΔQ|=0.552)
[   INFO] lenskit.algorithms.als [ 568ms] finished epoch 9 (|ΔP|=125.140, |ΔQ|=0.508)
[   INFO] lenskit.algorithms.als [ 623ms] finished epoch 10 (|ΔP|=109.817, |ΔQ|=0.456)
[   INFO] lenskit.algorithms.als [ 682ms] finished epoch 11 (|ΔP|=121.407, |ΔQ|=0.441)
[   INFO] lenskit.algorithms.als [ 746ms] finished epoch 12 (|ΔP|=105.041, |ΔQ|=0.405)
[   INFO] lenskit.algorithms.als [ 804ms] finished epoch 13 (|ΔP|=108.027, |ΔQ|=0.394)
[   INFO] lenskit.algorithms.als [ 858ms] finished epoch 14 (|ΔP|=100.251, |ΔQ|=0.369)
[   INFO] lenskit.algorithms.als [ 914ms] finished epoch 15 (|ΔP|=115.007, |ΔQ|=0.365)
[   INFO] lenskit.algorithms.als [ 969ms] finished epoch 16 (|ΔP|=97.391, |ΔQ|=0.350)
[   INFO] lenskit.algorithms.als [1.02s] finished epoch 17 (|ΔP|=88.497, |ΔQ|=0.329)
[   INFO] lenskit.algorithms.als [1.08s] finished epoch 18 (|ΔP|=84.539, |ΔQ|=0.310)
[   INFO] lenskit.algorithms.als [1.14s] finished epoch 19 (|ΔP|=91.381, |ΔQ|=0.305)
[   INFO] lenskit.algorithms.als [1.14s] finished training model with 50 features (|P|=2596.291220, |Q|=8.136999)
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm als.ImplicitMF(features=50, reg=0.1, w=40) in 1.15s
[   INFO] lenskit.batch._multi generating 670 predictions for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-wocg76xo.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._predict generating 670 predictions for 134 users
[   INFO] lenskit.batch._multi generated predictions in 1.97s
[   INFO] lenskit.batch._multi run 44: writing results to my-eval\predictions.parquet
[   INFO] lenskit.batch._multi generating recommendations for 134 users for TopN/als.ImplicitMF(features=50, reg=0.1, w=40)
[   INFO] lenskit.sharing persisting TopN/als.ImplicitMF(features=50, reg=0.1, w=40) to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-lkdqyfqa.bpk
[   INFO] binpickle.write pickled 1193 bytes with 8 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with TopN/als.ImplicitMF(features=50, reg=0.1, w=40) for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in 1.98s
[   INFO] lenskit.batch._multi generated recommendations in 2.17s
[   INFO] lenskit.batch._multi run 44: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 44: als.ImplicitMF(features=50, reg=0.1, w=40) on ML-Small:5
[   INFO] lenskit.batch._multi starting run 45: Popular on ML-Small:5
[   INFO] lenskit.batch._multi training algorithm Popular on 99334 ratings
[   INFO] lenskit.algorithms.basic trained unrated candidate selector for 99334 ratings
[   INFO] lenskit.batch._multi trained algorithm Popular in  13ms
[   INFO] lenskit.batch._multi generating recommendations for 134 users for Popular
[   INFO] lenskit.sharing persisting Popular to C:\Users\MICHAE~1\AppData\Local\Temp\lkpy-c79p1keh.bpk
[   INFO] binpickle.write pickled 967 bytes with 7 buffers
[   INFO] lenskit.util.parallel setting up ProcessPoolExecutor w/ 4 workers
[   INFO] lenskit.batch._recommend recommending with Popular for 134 users (n_jobs=None)
[   INFO] lenskit.batch._recommend recommended for 134 users in  802ms
[   INFO] lenskit.batch._multi generated recommendations in  874ms
[   INFO] lenskit.batch._multi run 45: writing results to my-eval\recommendations.parquet
[   INFO] lenskit.batch._multi finished run 45: Popular on ML-Small:5

Analysis

Now that the experiment is run, we can read its outputs.

First the run metadata:

In [11]:
runs = pd.read_csv('my-eval/runs.csv')
runs.set_index('RunId', inplace=True)
runs.head()
Out[11]:
DataSet Partition AlgoClass AlgoStr name features TrainTime PredTime RecTime
RunId
1 ML-Small 1 BiasedMF als.BiasedMF(features=20, regularization=0.1) BiasedMF 20.0 5.426783 2.066797 2.140798
2 ML-Small 1 BiasedMF als.BiasedMF(features=30, regularization=0.1) BiasedMF 30.0 0.444219 2.011823 2.139281
3 ML-Small 1 BiasedMF als.BiasedMF(features=40, regularization=0.1) BiasedMF 40.0 0.496614 1.942132 2.097481
4 ML-Small 1 BiasedMF als.BiasedMF(features=50, regularization=0.1) BiasedMF 50.0 0.633261 1.894300 2.060676
5 ML-Small 1 ImplicitMF als.ImplicitMF(features=20, reg=0.1, w=40) ImplicitMF 20.0 8.072543 2.431842 2.097856

This describes each run - a data set, partition, and algorithm combination. To evaluate, we need to get the actual recommendations, and combine them with this:

In [12]:
recs = pd.read_parquet('my-eval/recommendations.parquet')
recs.head()
Out[12]:
item score user rank RunId
0 3469 4.753794 10 1 1
1 913 4.718944 10 2 1
2 2064 4.712152 10 3 1
3 969 4.706261 10 4 1
4 3088 4.683724 10 5 1

We're going to compute per-(run,user) evaluations of the recommendations before combining with metadata.

In order to evaluate the recommendation list, we need to build a combined set of truth data. Since this is a disjoint partition of users over a single data set, we can just concatenate the individual test frames:

In [13]:
truth = pd.concat((p.test for p in pairs), ignore_index=True)

Now we can set up an analysis and compute the results.

In [14]:
rla = topn.RecListAnalysis()
rla.add_metric(topn.ndcg)
raw_ndcg = rla.compute(recs, truth)
raw_ndcg.head()
[   INFO] lenskit.topn analyzing 120780 recommendations (3355 truth rows)
[   INFO] lenskit.topn using group columns ['user', 'RunId']
[   INFO] lenskit.topn ungrouped columns: ['item', 'score', 'rank']
[   INFO] lenskit.topn using truth ID columns ['user']
[   INFO] lenskit.topn computing analysis for 6039 lists
[   INFO] lenskit.topn analyzed 6039 lists in 2.71s
Out[14]:
nrecs ndcg
user RunId
1 28 20.0 0.000000
29 20.0 0.000000
30 20.0 0.000000
31 20.0 0.000000
32 20.0 0.164037

Next, we need to combine this with our run data, so that we know what algorithms and configurations we are evaluating:

In [15]:
ndcg = raw_ndcg.join(runs[['AlgoClass', 'features']], on='RunId')
ndcg.head()
Out[15]:
nrecs ndcg AlgoClass features
user RunId
1 28 20.0 0.000000 BiasedMF 20.0
29 20.0 0.000000 BiasedMF 30.0
30 20.0 0.000000 BiasedMF 40.0
31 20.0 0.000000 BiasedMF 50.0
32 20.0 0.164037 ImplicitMF 20.0

We can compute the overall average performance for each algorithm configuration - fillna makes the group-by happy with Popular's lack of a feature count:

In [16]:
ndcg.fillna(0).groupby(['AlgoClass', 'features'])['ndcg'].mean()
Out[16]:
AlgoClass   features
BiasedMF    20.0        0.016942
            30.0        0.018656
            40.0        0.022978
            50.0        0.024254
ImplicitMF  20.0        0.086721
            30.0        0.101501
            40.0        0.103832
            50.0        0.117933
Popular     0.0         0.086276
Name: ndcg, dtype: float64

Now, we can plot this:

In [17]:
mf_scores = ndcg.groupby(['AlgoClass', 'features'])['ndcg'].mean().reset_index()
pop_score = ndcg[ndcg['AlgoClass'] == 'Popular']['ndcg'].mean()
plt.axhline(pop_score, color='grey', linestyle='--', label='Popular')
for algo, data in mf_scores.groupby('AlgoClass'):
    plt.plot(data['features'], data['ndcg'], label=algo)
plt.legend()
plt.xlabel('Features')
plt.ylabel('nDCG')
Out[17]:
Text(0, 0.5, 'nDCG')
In [ ]: