Using corpus_file does not speed up while the CPU utilization seems full. #3089

Donghyun-Kang-Soc · 2021-03-25T17:00:18Z

Problem description

I'm struggling with the issue of speeding up a doc2vec training using corpus_file after my institution introduced a new computing server system. With the previous system, I had/have no problem, but I found that the same script takes drastically different times, and I'm not enjoying the quasi-linear speed-up with the number of threads/cores anymore. I have not been able to find a solution for this issue, so I decided to post this here.

Steps/code/corpus to reproduce

The script is simple as below. The test.txt file is in LineSentence format as this page suggests. (The wide windows=240 is chosen to check out the CPU usage.)

import logging
import time
logging.basicConfig(level=logging.INFO)
from gensim.models.doc2vec import Doc2Vec

file = 'test.txt'

start_time = time.time()
model = Doc2Vec(vector_size=100, min_count=10, window=240, workers=24, seed=111, dm=0, dbow_words=1)
model.build_vocab(corpus_file=file)
print(time.time() - start_time, 'build vocab')

start_time = time.time()
model.train(corpus_file=file, total_examples=model.corpus_count, total_words=model.corpus_total_words, epochs=1)
print(time.time() - start_time, '1-epoch')

Running this with the previous server system, the 1-epoch time was

INFO:gensim.models.word2vec:EPOCH - 1 : training on 4182347 raw words (3516440 effective words) took 13.7s, 256302 effective words/s

While with the new system, the 1- epoch time was

INFO:gensim.models.word2vec:EPOCH - 1 : training on 4182347 raw words (3516440 effective words) took 88.8s, 39578 effective words/s

I checked out the CPU utilization from the new system (with the current issue) and it seemed that it was using 2400%.

I tried to use 48 cores, it again used the full 48 cores as below.

But, the training time was identical from the 24 core training.

NFO:gensim.models.word2vec:EPOCH - 1 : training on 4184193 raw words (3518530 effective words) took 87.7s, 40107 effective words/s

While I'm not putting it here, this happens not only from Gensim 4.0 but also from 3.8.3. I understand a wrong hardware configuration might cause this, so I will close this issue if I can confirm that. But I wanted to know if any developers/other users encountered a case similar to what I have now...

Versions

From the new system (with the training speed issue)

Linux-4.18.0-193.el8.x86_64-x86_64-with-glibc2.10
Python 3.8.5 (default, Sep  4 2020, 07:30:14) 
[GCC 7.3.0]
Bits 64
NumPy 1.20.1
SciPy 1.5.2
gensim 4.0.0
FAST_VERSION 1

From the previous system (where the corpus_file method worked.)

Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-redhat-7.4-Nitrogen
Python 3.7.6 (default, Jan  8 2020, 19:59:22) 
[GCC 7.3.0]
Bits 64
NumPy 1.18.5
SciPy 1.5.0
gensim 4.0.0
FAST_VERSION 1

The text was updated successfully, but these errors were encountered:

piskvorky · 2021-03-25T17:09:18Z

Hmm, do you know what changed between the new and old servers, specifically?

Do the two systems link a different BLAS library? (numpy.show_config())

At runtime, is the setting for BLAS threading different? (e.g. OMP_NUM_THREADS, or similar depending on your BLAS vendor)

Also, can you share test.txt so we can reproduce.

Donghyun-Kang-Soc · 2021-03-25T18:01:27Z

@piskvorky Thanks for your quick response!!

I heard that the new system changes the file storage system which aims to improve file I/O performance. Three main changes: 1) HDD to SSD; 2) bundling metadata and files for small files; 3) CPU from 28 x Intel E5-2680v4 @ 2.4 GHz to 2x Intel Xeon Gold 6248R.
I'm putting the results from numpy.show_config().

From the new system:

blas_mkl_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/software/python-anaconda-2020.11-el8-x86_64/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/software/python-anaconda-2020.11-el8-x86_64/include']
blas_opt_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/software/python-anaconda-2020.11-el8-x86_64/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/software/python-anaconda-2020.11-el8-x86_64/include']
lapack_mkl_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/software/python-anaconda-2020.11-el8-x86_64/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/software/python-anaconda-2020.11-el8-x86_64/include']
lapack_opt_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/software/python-anaconda-2020.11-el8-x86_64/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/software/python-anaconda-2020.11-el8-x86_64/include']

From the old system:

blas_mkl_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/software/python-anaconda-2020.02-el7-x86_64/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/software/python-anaconda-2020.02-el7-x86_64/include']
blas_opt_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/software/python-anaconda-2020.02-el7-x86_64/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/software/python-anaconda-2020.02-el7-x86_64/include']
lapack_mkl_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/software/python-anaconda-2020.02-el7-x86_64/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/software/python-anaconda-2020.02-el7-x86_64/include']
lapack_opt_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/software/python-anaconda-2020.02-el7-x86_64/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/software/python-anaconda-2020.02-el7-x86_64/include']

I found the two similar...

I'm not familiar with the BLAS setting so I'm not sure how to check what you suggested (OMP_NUM_THREADS). I think this might be the issue.
The input file is here.

I hope this further clarifies my issue.

piskvorky · 2021-03-25T19:46:38Z

I'm not familiar with the BLAS setting so I'm not sure how to check what you suggested (OMP_NUM_THREADS).

This is an environment variable. You set it before you launch your process (python interpreter, script). You can check its value from os.environ. For the MKL BLAS that you have, the variable seems to be called MKL_NUM_THREADS:

print(os.environ.get("MKL_NUM_THREADS", "not set")

Or else the two CPUs (their caches, architectures) are sufficiently different that the slowdown is "real", IDK. But I'd first try to rule out the BLAS threading difference.

What numbers do you get for the following, on either machine?

$ ipython

import numpy

x = numpy.random.rand(1000, 1000)
timeit numpy.dot(x, x.T)

Donghyun-Kang-Soc · 2021-03-25T20:22:58Z

1.The output from `print(os.environ.get("MKL_NUM_THREADS", "not set"))`

From the new system:

Python 3.8.5 (default, Sep  4 2020, 07:30:14) 
[GCC 7.3.0] :: Anaconda, Inc. on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import os
>>> print(os.environ.get("MKL_NUM_THREADS", "not set"))
not set

From the old system:

Python 3.7.6 (default, Jan  8 2020, 19:59:22) 
[GCC 7.3.0] :: Anaconda, Inc. on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import os
>>> print(os.environ.get("MKL_NUM_THREADS", "not set"))
not set

Does this mean that I have not been using BLAS even from the previous system?

2. The `timeit` results for `numpy.dot(x, x.T)`

From the new system

27.8 ms ± 16.4 µs per loop (mean ± std. dev. of 7 runs, 10 loops each)

From the old system

28.7 ms ± 321 µs per loop (mean ± std. dev. of 7 runs, 10 loops each)

Note that I used a single core/thread from both systems to produce the results above.

I wonder if those results rule out the possible BLAS issue.

piskvorky · 2021-03-25T20:36:46Z

Does this mean that I have not been using BLAS even from the previous system?

No, it means the BLAS lib was using default threading. I don't know what that is for MKL – probably "no thread limit, let MKL decide".

Note that I used a single core/thread from both systems to produce the results above.

How did you ensure that?

Donghyun-Kang-Soc · 2021-03-25T20:44:38Z

As for the thread/core number, I'm using the slurm scheduler (or sbatch) so I set the number of nodes/tasks/CPUS explicitly. I set it as --ntasks=1 --cpus-per-task=1 for the both systems for the numpy dot product test.

piskvorky · 2021-03-25T20:47:55Z

Instead, can you try running the timeit in the exact same way you run your doc2vec code?

Donghyun-Kang-Soc · 2021-03-25T22:09:51Z

Okay... I wrote a quick script as below and ran it by submitting it within the two systems, using --ntasks=1 --cpus-per-task=24 as arguments in SBATCH.

#!/usr/bin/env python
# coding: utf-8


# importing the required module 
import timeit 
import numpy as np
  
my_setup = "import numpy as np;x = np.random.rand(1000, 1000)"

# code snippet whose execution time is to be measured 
my_code = "np.dot(x, x.T)"
  
# timeit statement 
result_lst = []
for i in range(1,11):
	result = timeit.repeat(setup = my_setup,stmt = my_code, number = 100)
	result_lst.append(np.mean(result))

result_array = np.array(result_lst)
print(result_array.mean(), result_array.std())

The result from the old system was

[0.82416547 0.7230122  0.52124183 0.5228327  0.52300834 0.52314769
 0.52203556 0.52187336 0.52241195 0.52144711]
0.5725176205486059 0.10305031288100999

The result from the new system was

[0.25239568 0.25034589 0.25028389 0.25023676 0.25043886 0.25023319
 0.25043233 0.25020592 0.25029072 0.2505656 ]

0.25054288486950094 0.0006268202851826956

piskvorky · 2021-03-25T22:12:42Z

And this (--ntasks=1 --cpus-per-task=24 as arguments in SBATCH) is how you got the Doc2Vec timings in your original post?

Donghyun-Kang-Soc · 2021-03-25T22:27:28Z

Okay, I find it as

#SBATCH --nodes=1		
#SBATCH --ntasks-per-node=1
#SBATCH --cpus-per-task=24

which might have been an issue.

So, I tried the same script with

--ntasks=1 
--cpus-per-task=24

But the result was the same as I'm pasting here. (Again, the CPU utilization was 2400%)

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w240,mc10,s0.001,t24)', 'datetime': '2021-03-25T17:23:49.219568', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-4.18.0-193.el8.x86_64-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-03-25T17:23:50.183738', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-4.18.0-193.el8.x86_64-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-03-25T17:23:50.183840', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-4.18.0-193.el8.x86_64-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-03-25T17:23:50.270676', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-4.18.0-193.el8.x86_64-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 24 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=240', 'datetime': '2021-03-25T17:23:50.524125', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-4.18.0-193.el8.x86_64-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 4.96% examples, 2759 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 23 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 9.55% examples, 5213 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 22 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 21 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 18.65% examples, 10213 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 20 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 19 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 27.44% examples, 14909 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 18 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 17 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 35.97% examples, 19185 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 16 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 15 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 14 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 13 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 52.87% examples, 28380 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 12 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 11 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 10 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 9 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 69.61% examples, 36635 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 8 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 7 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 6 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 5 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 93.06% examples, 49924 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 99.92% examples, 53762 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4182347 raw words (3516440 effective words) took 65.4s, 53762 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4182347 raw words (3516440 effective words) took 65.4s, 53727 effective words/s', 'datetime': '2021-03-25T17:24:55.973927', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-4.18.0-193.el8.x86_64-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.utils:Doc2Vec lifecycle event {'fname_or_handle': 'train_test.d2v', 'separately': 'None', 'sep_limit': 10485760, 'ignore': frozenset(), 'datetime': '2021-03-25T17:24:55.974117', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-4.18.0-193.el8.x86_64-x86_64-with-glibc2.10', 'event': 'saving'}
INFO:gensim.utils:not storing attribute cum_table
INFO:gensim.utils:saved train_test.d2v
1.2659120559692383 build vocab
65.48883509635925 1-epoch

As for a reference, I'm pasting the log from the previous system

NFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow,d100,n5,mc10,s0.001,t24)', 'datetime': '2021-03-25T17:30:38.965505', 'gensim': '4.0.0', 'python': '3.7.6 (default, Jan  8 2020, 19:59:22) \n[GCC 7.3.0]', 'platform': 'Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-redhat-7.4-Nitrogen', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #10000, processed 444086 words (2863939/s), 27079 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #20000, processed 859805 words (2962252/s), 36743 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #30000, processed 1286757 words (3269897/s), 45870 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #40000, processed 1693282 words (3345412/s), 51506 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #50000, processed 2099720 words (3303597/s), 57679 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #60000, processed 2505682 words (3307495/s), 63115 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #70000, processed 2913240 words (3284645/s), 67828 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #80000, processed 3281610 words (3253610/s), 70907 word types, 0 tags
INFO:gensim.models.doc2vec:PROGRESS: at example #90000, processed 3690633 words (3230803/s), 74272 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-03-25T17:30:40.386467', 'gensim': '4.0.0', 'python': '3.7.6 (default, Jan  8 2020, 19:59:22) \n[GCC 7.3.0]', 'platform': 'Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-redhat-7.4-Nitrogen', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-03-25T17:30:40.386577', 'gensim': '4.0.0', 'python': '3.7.6 (default, Jan  8 2020, 19:59:22) \n[GCC 7.3.0]', 'platform': 'Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-redhat-7.4-Nitrogen', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-03-25T17:30:40.519855', 'gensim': '4.0.0', 'python': '3.7.6 (default, Jan  8 2020, 19:59:22) \n[GCC 7.3.0]', 'platform': 'Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-redhat-7.4-Nitrogen', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 24 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=240', 'datetime': '2021-03-25T17:30:40.898408', 'gensim': '4.0.0', 'python': '3.7.6 (default, Jan  8 2020, 19:59:22) \n[GCC 7.3.0]', 'platform': 'Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-redhat-7.4-Nitrogen', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 3.20% examples, 77532 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 23 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 22 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 21 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 20 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 19 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 18 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 17 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 16 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 15 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 14 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 13 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 12 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 11 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 10 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 9 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 8 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 7 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 6 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 5 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4182347 raw words (3516441 effective words) took 2.3s, 1519355 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4182347 raw words (3516441 effective words) took 2.4s, 1478955 effective words/s', 'datetime': '2021-03-25T17:30:43.276454', 'gensim': '4.0.0', 'python': '3.7.6 (default, Jan  8 2020, 19:59:22) \n[GCC 7.3.0]', 'platform': 'Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-redhat-7.4-Nitrogen', 'event': 'train'}
INFO:gensim.utils:Doc2Vec lifecycle event {'fname_or_handle': 'train_test.d2v', 'separately': 'None', 'sep_limit': 10485760, 'ignore': frozenset(), 'datetime': '2021-03-25T17:30:43.276769', 'gensim': '4.0.0', 'python': '3.7.6 (default, Jan  8 2020, 19:59:22) \n[GCC 7.3.0]', 'platform': 'Linux-3.10.0-1127.8.2.el7.x86_64-x86_64-with-redhat-7.4-Nitrogen', 'event': 'saving'}
INFO:gensim.utils:not storing attribute cum_table
INFO:gensim.utils:saved train_test.d2v
1.8741874694824219 build vocab
2.4373130798339844 1 epoch

Is the corpus_file method possibly dependent on the file I/O system in some cases? Or could you think of additional possible bottle necks or something? (I indeed appreciate all the responses...)

Donghyun-Kang-Soc · 2021-03-26T02:08:45Z

Hello, I'm writing this to report because I faced with the same issue with another machine independent from the two systems I've been using. The input data and the code is the same as before.

1. The environment is as below

Linux-5.3.0-61-generic-x86_64-with-glibc2.10
Python 3.8.5 (default, Sep  4 2020, 07:30:14)
[GCC 7.3.0]
Bits 64
NumPy 1.19.2
SciPy 1.5.2
gensim 4.0.0
FAST_VERSION 1

2. The result from numpy.show_config()

Python 3.8.5 (default, Sep  4 2020, 07:30:14)
[GCC 7.3.0] :: Anaconda, Inc. on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import numpy
>>> numpy.show_config()
blas_mkl_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/home/donghyun/anaconda3/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/home/donghyun/anaconda3/include']
blas_opt_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/home/donghyun/anaconda3/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/home/donghyun/anaconda3/include']
lapack_mkl_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/home/donghyun/anaconda3/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/home/donghyun/anaconda3/include']
lapack_opt_info:
    libraries = ['mkl_rt', 'pthread']
    library_dirs = ['/home/donghyun/anaconda3/lib']
    define_macros = [('SCIPY_MKL_H', None), ('HAVE_CBLAS', None)]
    include_dirs = ['/home/donghyun/anaconda3/include']

3. Training performance

3.1 workers =1

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w240,mc10,s0.001)', 'datetime': '2021-03-25T20:49:55.132061', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-03-25T20:49:56.119412', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-03-25T20:49:56.119596', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-03-25T20:49:56.241771', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.3674097061157227 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 1 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=240', 'datetime': '2021-03-25T20:49:56.499435', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 100.00% examples, 31697 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4184045 raw words (3517716 effective words) took 111.0s, 31697 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4184045 raw words (3517716 effective words) took 111.0s, 31688 effective words/s', 'datetime': '2021-03-25T20:51:47.511129', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

3.2 workers =5

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w240,mc10,s0.001,t5)', 'datetime': '2021-03-25T20:55:18.121501', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-03-25T20:55:19.151606', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-03-25T20:55:19.151795', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-03-25T20:55:19.265861', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.3985042572021484 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 5 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=240', 'datetime': '2021-03-25T20:55:19.558765', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 21.77% examples, 3417 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 42.33% examples, 6491 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 62.45% examples, 9756 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 81.88% examples, 12726 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 99.84% examples, 15768 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4178059 raw words (3513134 effective words) took 222.8s, 15768 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4178059 raw words (3513134 effective words) took 222.8s, 15765 effective words/s', 'datetime': '2021-03-25T20:59:02.402655', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

3.3 workers =20

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w240,mc10,s0.001,t20)', 'datetime': '2021-03-25T21:06:30.070994', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-03-25T21:06:31.070140', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-03-25T21:06:31.070326', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-03-25T21:06:31.191505', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.3794331550598145 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 20 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=240', 'datetime': '2021-03-25T21:06:31.494918', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 5.93% examples, 2073 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 19 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 11.19% examples, 3987 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 18 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 16.60% examples, 5841 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 17 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 22.16% examples, 7661 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 16 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 27.56% examples, 9376 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 15 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 14 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 37.88% examples, 12754 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 13 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 12 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 48.13% examples, 16139 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 11 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 53.22% examples, 16868 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 10 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 9 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 63.20% examples, 19999 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 8 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 68.09% examples, 21334 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 7 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 72.97% examples, 22667 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 6 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 5 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 87.30% examples, 27378 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 91.62% examples, 28402 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 99.91% examples, 31291 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4181642 raw words (3516536 effective words) took 112.4s, 31291 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4181642 raw words (3516536 effective words) took 112.4s, 31273 effective words/s', 'datetime': '2021-03-25T21:08:23.941539', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

The CPU utilization appears as it is supposed. Plus, I tested with dm=1 and different (smaller) window sizes, but the issue seems to persist...

piskvorky · 2021-03-26T07:50:47Z

Thank you for the detailed reports.

I'm not sure what the problem is – this will have to wait until someone has the time to reproduce & dig deeper.

Donghyun-Kang-Soc · 2021-03-26T15:16:39Z

@piskvorky Thanks for all the responses. I will post further here if I find something worthwhile sharing.

Donghyun-Kang-Soc · 2021-03-26T19:11:10Z

@piskvorky I'm sharing this to ask if this might be related with the current issue. Thanks.

piskvorky · 2021-03-26T19:32:32Z

Well that's exactly what we were checking above – whether your BLAS is parallelized.

I'm not familiar with slurm, but my understanding of the experiments you reported is that your trouble persists even when you use a single core.

That is, the doc2vec training is slower even when restricted to a single core. So it cannot be an issue of multithreading / multiprocessing.

Donghyun-Kang-Soc · 2021-03-26T19:55:52Z

@piskvorky I see. (Just to remind, the third experiment was conducted under a server machine without using any slurm scheduling.) I will dig a bit more about the previous system's configurations from which I can benefit from the multicores. This is interestingly confusing/frustrating... But thanks!

gojomo · 2021-04-01T04:24:07Z

The third experiment is strange in that both workers=1 & workers=20 finish in ~111s, while workers=5 finishes in exactly twice as long. Are you sure they were all run with otherwise-identical settings? Are you sure nothing else was running on the machine? Does repeating each run give a similar time?

Is window=240 really what you need for you actual project training? (By making individual noGIL blocks run much longer than usual, such a setting will change the threading-contention quite a bit. With such a setting, the corpus_file advantage over corpus-iterable might be neglible, unless you re-confirm it in your setup. What's the runtime difference on each machine, with same test code, in corpus_file vs corpus_iterable=LineSentence(file) modes?)

Are these systems true machines, or VMs under some virtualization?

Normally an HDD to SSD upgrade would be a big boost if IO was any part of the bottleneck.

I'm unsure what "28 x Intel E5-2680v4" means in terms of true cores. 28 CPUs with 14 cores each, for 392 (!) cores? If so, that sounds like more actual cores than "2x Intel Xeon Gold 6248R", 2 CPUs of 24 cores each, for 48 total cores. Might the answer be as simple as that? (What does import multiprocessing;print(multiprocessing.cpu_count() report on each machine?)

Despite the unset _NUM_THREADS it's possible there are different defaults for the math libraries to try their own multithreading - and when that library is trying multithreading atop the model algorithm worker threads, the contention may negate the advantage of either alone. (However, to the extent your top readouts always show the parent process with a roughly expected CPU% for your workers value, it doesn't seem any more contention is happening - unless it's in other top lines you've elided?)

Donghyun-Kang-Soc · 2021-04-01T22:43:51Z

@gojomo Thanks for your detailed response. I'm sharing with you what I rechecked.

1. Rechecking the running time

I rechecked the running times using 1, 10, 20 cores with the third machine. I believe I ran them with identical settings. I'm attaching the

1.1 1 workers

INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 1 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=240', 'datetime': '2021-04-01T16:17:33.126095', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 100.00% examples, 32620 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4184045 raw words (3517716 effective words) took 107.8s, 32620 effective words/s

1.2- 5 workers

INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 5 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=240', 'datetime': '2021-04-01T16:21:16.175880', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 21.77% examples, 3305 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 41.88% examples, 6545 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 81.88% examples, 12898 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 99.84% examples, 15930 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4178059 raw words (3513134 effective words) took 220.5s, 15930 effective words/s

1.3 20 workers

INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 20 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=240', 'datetime': '2021-04-01T16:28:21.121793', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 5.93% examples, 2081 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 19 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 11.35% examples, 3866 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 18 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 17 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 22.16% examples, 7503 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 16 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 15 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 14 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 37.88% examples, 12669 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 13 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 43.14% examples, 14275 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 12 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 11 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 53.22% examples, 17397 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 10 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 58.10% examples, 18956 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 9 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 63.20% examples, 20315 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 8 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 7 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 72.96% examples, 23137 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 6 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 77.85% examples, 24329 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 5 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 82.68% examples, 25621 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 91.62% examples, 28412 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 99.91% examples, 31276 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4181642 raw words (3516536 effective words) took 112.4s, 31276 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4181642 raw words (3516536 effective words) took 112.5s, 31258 effective words/s', 'datetime': '2021-04-01T16:30:13.621991', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

I think the running times are not different from what I shared last time.

2. Rechecking the running time with window = 10
(vector_size=100, min_count=10, window=10, seed=111, dm=0, dbow_words=1)

I think I have the same issue with a smaller window size.

2.1 1 workers

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w10,mc10,s0.001)', 'datetime': '2021-04-01T16:32:44.171368', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-04-01T16:32:45.183664', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-04-01T16:32:45.183792', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-04-01T16:32:45.308314', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.3846714496612549 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 1 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=10', 'datetime': '2021-04-01T16:32:45.555952', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 100.00% examples, 112741 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4184045 raw words (3517255 effective words) took 31.2s, 112739 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4184045 raw words (3517255 effective words) took 31.2s, 112641 effective words/s', 'datetime': '2021-04-01T16:33:16.781427', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

2.2 5 workers

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w10,mc10,s0.001,t5)', 'datetime': '2021-04-01T16:33:57.883533', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-04-01T16:33:58.845714', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-04-01T16:33:58.845833', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-04-01T16:33:58.966120', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.3341550827026367 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 5 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=10', 'datetime': '2021-04-01T16:33:59.254193', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 19.43% examples, 11360 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 41.20% examples, 21695 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 61.77% examples, 31788 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4178059 raw words (3512873 effective words) took 66.7s, 52693 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4178059 raw words (3512873 effective words) took 66.7s, 52665 effective words/s', 'datetime': '2021-04-01T16:35:05.955941', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
66.73864698410034 1 epoch

2.3 20 workers

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w10,mc10,s0.001,t20)', 'datetime': '2021-04-01T16:35:55.555033', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-04-01T16:35:56.519126', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-04-01T16:35:56.519247', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-04-01T16:35:56.638570', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.3372654914855957 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 20 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=10', 'datetime': '2021-04-01T16:35:56.934247', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 5.56% examples, 6513 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 19 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 18 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 17 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 16 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 15 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 32.53% examples, 37036 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 14 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 13 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 12 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 11 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 10 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 9 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 8 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 7 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 6 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 5 more threads
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 81.91% examples, 96341 words/s, in_qsize -1, out_qsize 1
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4181642 raw words (3516056 effective words) took 29.2s, 120372 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4181642 raw words (3516056 effective words) took 29.3s, 120101 effective words/s', 'datetime': '2021-04-01T16:36:26.210190', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

3. Checking the running times for TaggedLineDocument(file)

vector_size=100, min_count=10, window=10, seed=111, dm=0, dbow_words=1

For example, the scripts are like

model = Doc2Vec(vector_size=100, min_count=10, window=10, workers=8, seed=111, dm=0, dbow_words=1)
model.build_vocab(corpus_iterable=TaggedLineDocument(file))
model.train(corpus_iterable=TaggedLineDocument(file), total_examples=model.corpus_count, total_words=model.corpus_total_words, epochs=1)

I did this with the third machine.

3.1 1 worker

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w10,mc10,s0.001)', 'datetime': '2021-04-01T16:48:23.212387', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-04-01T16:48:24.257932', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-04-01T16:48:24.258060', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-04-01T16:48:24.379191', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.4240179061889648 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 1 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=10', 'datetime': '2021-04-01T16:48:24.636237', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 2.57% examples, 93775 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 5.05% examples, 93076 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 7.52% examples, 91675 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 9.89% examples, 90758 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 12.64% examples, 91644 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 15.56% examples, 92294 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 18.50% examples, 92726 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 21.41% examples, 93023 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 24.12% examples, 93212 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 26.85% examples, 93276 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 29.75% examples, 93403 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 32.67% examples, 93577 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 35.61% examples, 93729 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 38.65% examples, 93890 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 41.53% examples, 93983 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 44.36% examples, 94059 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 47.31% examples, 94086 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 50.37% examples, 94134 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 53.30% examples, 94113 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 56.24% examples, 94218 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 59.19% examples, 94281 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 62.08% examples, 94376 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 64.81% examples, 94411 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 67.91% examples, 94413 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 71.00% examples, 94443 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 74.14% examples, 94479 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 77.42% examples, 94478 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 80.88% examples, 94431 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 84.11% examples, 94465 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 87.14% examples, 94511 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 89.67% examples, 94554 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 91.81% examples, 94600 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 94.25% examples, 94603 words/s, in_qsize 1, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 96.55% examples, 94422 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 98.86% examples, 94260 words/s, in_qsize 2, out_qsize 0
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4184045 raw words (3518203 effective words) took 37.3s, 94243 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4184045 raw words (3518203 effective words) took 37.3s, 94241 effective words/s', 'datetime': '2021-04-01T16:49:01.968546', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

3.2 4 workers

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w10,mc10,s0.001,t4)', 'datetime': '2021-04-01T16:50:25.309123', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-04-01T16:50:26.290612', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-04-01T16:50:26.290734', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-04-01T16:50:26.408559', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.3618228435516357 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 4 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=10', 'datetime': '2021-04-01T16:50:26.670768', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 2.11% examples, 49094 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 3.92% examples, 49976 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 5.76% examples, 51391 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 7.52% examples, 50797 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 9.23% examples, 50611 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 11.04% examples, 50989 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 12.64% examples, 51797 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 14.36% examples, 51846 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 16.31% examples, 51800 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 18.24% examples, 51534 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 20.20% examples, 51358 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 22.17% examples, 51453 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 23.70% examples, 51919 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 24.71% examples, 51329 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 26.34% examples, 51583 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 27.84% examples, 51297 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 29.48% examples, 51554 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 30.99% examples, 51262 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 32.67% examples, 51201 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 34.32% examples, 51472 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 35.89% examples, 51299 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 37.67% examples, 51153 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 39.35% examples, 51352 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 41.07% examples, 51381 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 42.70% examples, 51380 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 44.13% examples, 51334 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 45.49% examples, 51295 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 47.31% examples, 51415 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 49.08% examples, 51595 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 50.59% examples, 51264 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 52.34% examples, 51300 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 54.24% examples, 51327 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 55.99% examples, 51488 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 57.46% examples, 51356 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 59.45% examples, 51369 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 61.43% examples, 51400 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 63.18% examples, 51344 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 65.07% examples, 51444 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 67.18% examples, 51461 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 69.19% examples, 51560 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 71.25% examples, 51619 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 73.38% examples, 51727 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 74.93% examples, 51612 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 76.87% examples, 51546 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 79.18% examples, 51587 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 81.46% examples, 51704 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 83.61% examples, 51838 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 85.63% examples, 51931 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 87.14% examples, 51874 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 88.84% examples, 51734 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 90.22% examples, 51696 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 91.62% examples, 51627 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 93.21% examples, 51623 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 94.89% examples, 51648 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 96.13% examples, 51624 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 97.36% examples, 51594 words/s, in_qsize 8, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 98.66% examples, 51555 words/s, in_qsize 7, out_qsize 0
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4184045 raw words (3517195 effective words) took 67.9s, 51809 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4184045 raw words (3517195 effective words) took 67.9s, 51808 effective words/s', 'datetime': '2021-04-01T16:51:34.559951', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

3.2 8 workers

INFO:gensim.utils:Doc2Vec lifecycle event {'params': 'Doc2Vec(dbow+w,d100,n5,w10,mc10,s0.001,t8)', 'datetime': '2021-04-01T16:52:44.012570', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'created'}
INFO:gensim.models.doc2vec:collecting all words and their counts
INFO:gensim.models.doc2vec:PROGRESS: at example #0, processed 0 words (0/s), 0 word types, 0 tags
INFO:gensim.models.doc2vec:collected 77665 word types and 100000 unique tags from a corpus of 100000 examples and 4184045 words
INFO:gensim.models.word2vec:Creating a fresh vocabulary
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 retains 20679 unique words (26.625893259512008%% of original 77665, drops 56986)', 'datetime': '2021-04-01T16:52:45.025073', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'effective_min_count=10 leaves 4027886 word corpus (96.26775046635493%% of original 4184045, drops 156159)', 'datetime': '2021-04-01T16:52:45.025192', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:deleting the raw counts dictionary of 77665 items
INFO:gensim.models.word2vec:sample=0.001 downsamples 28 most-common words
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'downsampling leaves estimated 3417868.315568148 word corpus (84.9%% of prior 4027886)', 'datetime': '2021-04-01T16:52:45.146537', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'prepare_vocab'}
INFO:gensim.models.word2vec:estimated required memory for 20679 words and 100 dimensions: 86882700 bytes
INFO:gensim.models.word2vec:resetting layer weights
1.3878040313720703 build vocab
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training model with 8 workers on 20679 vocabulary and 100 features, using sg=1 hs=0 sample=0.001 negative=5 window=10', 'datetime': '2021-04-01T16:52:45.400193', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 2.10% examples, 40133 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 3.91% examples, 48179 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 5.76% examples, 51862 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 7.52% examples, 54093 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 9.23% examples, 54818 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 11.04% examples, 55550 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 12.87% examples, 56414 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 14.84% examples, 56150 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 16.82% examples, 55804 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 18.75% examples, 55974 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 20.68% examples, 56401 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 21.92% examples, 55366 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 23.34% examples, 54989 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 24.92% examples, 54698 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 26.82% examples, 54807 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 28.79% examples, 54685 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 30.73% examples, 54652 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 32.67% examples, 54887 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 34.59% examples, 55283 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 36.42% examples, 55295 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 38.40% examples, 55507 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 40.06% examples, 55438 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 41.53% examples, 55179 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 43.19% examples, 55137 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 44.82% examples, 55082 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 46.75% examples, 55211 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 48.82% examples, 55451 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 50.85% examples, 55549 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 52.58% examples, 55501 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 54.26% examples, 55469 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 55.99% examples, 55527 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 57.95% examples, 55646 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 59.71% examples, 55624 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 61.66% examples, 55538 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 63.40% examples, 55580 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 65.33% examples, 55670 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 67.18% examples, 55638 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 69.19% examples, 55830 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 71.25% examples, 55948 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 72.85% examples, 55719 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 74.69% examples, 55677 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 76.88% examples, 55805 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 79.18% examples, 55991 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 81.16% examples, 55997 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 83.35% examples, 55984 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 85.37% examples, 56005 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 87.41% examples, 56041 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 89.00% examples, 55870 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 90.39% examples, 55748 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 91.81% examples, 55677 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 93.42% examples, 55745 words/s, in_qsize 16, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 95.12% examples, 55817 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 96.55% examples, 55797 words/s, in_qsize 15, out_qsize 0
INFO:gensim.models.word2vec:EPOCH 1 - PROGRESS: at 97.80% examples, 55655 words/s, in_qsize 11, out_qsize 0
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 7 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 6 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 5 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 4 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 3 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 2 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 1 more threads
INFO:gensim.models.word2vec:worker thread finished; awaiting finish of 0 more threads
INFO:gensim.models.word2vec:EPOCH - 1 : training on 4184045 raw words (3518572 effective words) took 62.6s, 56199 effective words/s
INFO:gensim.utils:Doc2Vec lifecycle event {'msg': 'training on 4184045 raw words (3518572 effective words) took 62.6s, 56196 effective words/s', 'datetime': '2021-04-01T16:53:48.012280', 'gensim': '4.0.0', 'python': '3.8.5 (default, Sep  4 2020, 07:30:14) \n[GCC 7.3.0]', 'platform': 'Linux-5.3.0-61-generic-x86_64-with-glibc2.10', 'event': 'train'}

It seems like the similar issue occurred.

4. Others

All the three systems I used are not VMs.
I found that Intel E5-2680v4 has 14 cores/28 threads from the old system while the Intel Xeon Gold 6248Rhas 24 cores/48 threads. The third system has AMD Ryzen Threadripper 2970WX 24-Core Processor with 24 cores/48 threads.

I'm attaching results from import multiprocessing;print(multiprocessing.cpu_count().

From the old system (Intel E5-2680v4)

Python 3.7.6 (default, Jan  8 2020, 19:59:22)
[GCC 7.3.0] :: Anaconda, Inc. on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import multiprocessing;print(multiprocessing.cpu_count())
28

From the new system (Intel Xeon Gold 6248R)

Python 3.8.5 (default, Sep  4 2020, 07:30:14)
[GCC 7.3.0] :: Anaconda, Inc. on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import multiprocessing;print(multiprocessing.cpu_count())
48

The third system (AMD Ryzen Threadripper 2970WX 24-Core Processor)

Python 3.8.5 (default, Sep  4 2020, 07:30:14)
[GCC 7.3.0] :: Anaconda, Inc. on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import multiprocessing;print(multiprocessing.cpu_count())
48

Thank you very much. Please let me know if you have other suggestions that I can check out. (I will test the systems with other input files just to be sure.)

gojomo · 2023-10-31T04:11:55Z

Very belatedly, this behavior is still mysterious, especially where even a modest number of workers (5) with a typical window (1) goes slower than the 1-worker case.

Two low-confidence theories:

(1) some odd stall at some point; if logging had included timestamps per line, any single step taking a weird amount of time might have stuck out

(2) as previously mentioned, something weird with the BLAS library's own attempts to parallelize via *_NUM_THREADS-like behavior, where the workers=1 case is achieving effective parallelism but workers=5 somehow excessively contending/stalling

Separately, I note that the corpus_file runs with workers>1 report different 'raw words' counts than the worker=1 case (which agrees with the tradtional iterable/TaggedLineDocument count). There shouldn't be a difference; this may be another symptom of whatever's buggy about corpus_file mode in #2757. (Skipping tiny bits of training data may not have a very noticeable effect on overall final vector quality, in suitably large run – but at least in #2757 one effect seems to be that some docs get no training at all. That's a serious problem if you needed vectors for that data!)

piskvorky added the performance Issue related to performance (in HW meaning) label Mar 25, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Using corpus_file does not speed up while the CPU utilization seems full. #3089

Using corpus_file does not speed up while the CPU utilization seems full. #3089

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

piskvorky commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

piskvorky commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

piskvorky commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

piskvorky commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 25, 2021

piskvorky commented Mar 25, 2021

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 26, 2021 •

edited

Loading

piskvorky commented Mar 26, 2021

Donghyun-Kang-Soc commented Mar 26, 2021

Donghyun-Kang-Soc commented Mar 26, 2021

piskvorky commented Mar 26, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 26, 2021 •

edited

Loading

gojomo commented Apr 1, 2021

Donghyun-Kang-Soc commented Apr 1, 2021 •

edited

Loading

gojomo commented Oct 31, 2023

Using corpus_file does not speed up while the CPU utilization seems full. #3089

Using corpus_file does not speed up while the CPU utilization seems full. #3089

Comments

Donghyun-Kang-Soc commented Mar 25, 2021 • edited Loading

Problem description

Steps/code/corpus to reproduce

Versions

piskvorky commented Mar 25, 2021 • edited Loading

Donghyun-Kang-Soc commented Mar 25, 2021 • edited Loading

piskvorky commented Mar 25, 2021 • edited Loading

Donghyun-Kang-Soc commented Mar 25, 2021 • edited Loading

1.The output from print(os.environ.get("MKL_NUM_THREADS", "not set"))

2. The timeit results for numpy.dot(x, x.T)

piskvorky commented Mar 25, 2021 • edited Loading

Donghyun-Kang-Soc commented Mar 25, 2021 • edited Loading

piskvorky commented Mar 25, 2021 • edited Loading

Donghyun-Kang-Soc commented Mar 25, 2021

piskvorky commented Mar 25, 2021

Donghyun-Kang-Soc commented Mar 25, 2021 • edited Loading

Donghyun-Kang-Soc commented Mar 26, 2021 • edited Loading

1. The environment is as below

2. The result from numpy.show_config()

3. Training performance

3.1 workers =1

3.2 workers =5

3.3 workers =20

piskvorky commented Mar 26, 2021

Donghyun-Kang-Soc commented Mar 26, 2021

Donghyun-Kang-Soc commented Mar 26, 2021

piskvorky commented Mar 26, 2021 • edited Loading

Donghyun-Kang-Soc commented Mar 26, 2021 • edited Loading

gojomo commented Apr 1, 2021

Donghyun-Kang-Soc commented Apr 1, 2021 • edited Loading

gojomo commented Oct 31, 2023

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

piskvorky commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

piskvorky commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

1.The output from `print(os.environ.get("MKL_NUM_THREADS", "not set"))`

2. The `timeit` results for `numpy.dot(x, x.T)`

piskvorky commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

piskvorky commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 25, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 26, 2021 •

edited

Loading

piskvorky commented Mar 26, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Mar 26, 2021 •

edited

Loading

Donghyun-Kang-Soc commented Apr 1, 2021 •

edited

Loading