pkgcheck scan --commit: IndexError: pop from an empty deque

[mgorny]

pkgcheck scan: error: Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/pkgcheck/pipeline.py", line 186, in _run_checks
    if results := sorted(chain.from_iterable(
  File "/usr/lib/python3.9/site-packages/pkgcheck/runners.py", line 67, in run
    for item in self.source.itermatch(restrict):
  File "/usr/lib/python3.9/site-packages/pkgcheck/sources.py", line 36, in itermatch
    yield from self.source
  File "/usr/lib/python3.9/site-packages/pkgcheck/addons/git.py", line 183, in __next__
    pkgs = list(chain.from_iterable(pkgs for _, pkgs in self.changes))
  File "/usr/lib/python3.9/site-packages/pkgcheck/addons/git.py", line 183, in <genexpr>
    pkgs = list(chain.from_iterable(pkgs for _, pkgs in self.changes))
  File "/usr/lib/python3.9/site-packages/pkgcheck/addons/git.py", line 157, in changes
    path = changes.popleft()
IndexError: pop from an empty deque

If I debug-print the changes deque before the loop, I get:

deque(['M', 'sys-kernel/gentoo-kernel-bin/Manifest', 'A', 'sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.12.8.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel-bin/Manifest', 'A', 'sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.10.41.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel-bin/Manifest', 'A', 'sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.4.123.ebuild'])
deque(['A', 'virtual/dist-kernel/dist-kernel-5.12.8.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel/Manifest', 'A', 'sys-kernel/gentoo-kernel/gentoo-kernel-5.12.8.ebuild'])
deque(['M', 'sys-kernel/vanilla-kernel/Manifest', 'A', 'sys-kernel/vanilla-kernel/vanilla-kernel-5.12.8.ebuild'])
deque(['A', 'virtual/dist-kernel/dist-kernel-5.10.41.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel/Manifest', 'A', 'sys-kernel/gentoo-kernel/gentoo-kernel-5.10.41.ebuild'])
deque(['M', 'sys-kernel/vanilla-kernel/Manifest', 'A', 'sys-kernel/vanilla-kernel/vanilla-kernel-5.10.41.ebuild'])
deque(['A', 'virtual/dist-kernel/dist-kernel-5.4.123.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel/Manifest', 'A', 'sys-kernel/gentoo-kernel/gentoo-kernel-5.4.123.ebuild'])
deque(['M', 'sys-kernel/vanilla-kernel/Manifest', 'A', 'sys-kernel/vanilla-kernel/vanilla-kernel-5.4.123.ebuild'])
deque(['M', 'profiles/package.mask'])
deque(['M', 'dev-python/sphinxcontrib-github-alt/Manifest', 'A', 'dev-python/sphinxcontrib-github-alt/sphinxcontrib-github-alt-1.2.ebuild'])
deque(['M', 'dev-python/sphinxcontrib-doxylink/metadata.xml'])
deque(['M', 'dev-python/sphinxcontrib-doxylink/sphinxcontrib-doxylink-1.8.ebuild'])
deque(['M', 'dev-python/sphinxcontrib-doxylink/Manifest', 'A', 'dev-python/sphinxcontrib-doxylink/sphinxcontrib-doxylink-1.8.ebuild'])
deque(['M', 'dev-python/sphinxcontrib-newsfeed/metadata.xml'])
deque(['M', 'dev-python/sphinxcontrib-newsfeed/sphinxcontrib-newsfeed-0.1.4.ebuild'])
deque(['M', 'dev-python/sphinxcontrib-newsfeed/sphinxcontrib-newsfeed-0.1.4.ebuild'])
deque(['M', 'dev-python/sphinx-aiohttp-theme/metadata.xml'])
deque(['M', 'dev-python/sphinx-aiohttp-theme/sphinx-aiohttp-theme-0.1.6.ebuild'])
deque(['M', 'dev-python/sphinxcontrib-asyncio/metadata.xml'])
deque(['M', 'dev-python/sphinxcontrib-asyncio/sphinxcontrib-asyncio-0.2.0-r2.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel-bin/Manifest', 'A', 'sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.12.8.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel-bin/Manifest', 'A', 'sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.12.8.ebuild', 'ble doc generation'])
deque(['M', 'sys-kernel/gentoo-kernel-bin/Manifest', 'A', 'sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.10.41.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel-bin/Manifest', 'A', 'sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.4.123.ebuild'])
deque(['A', 'virtual/dist-kernel/dist-kernel-5.12.8.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel/Manifest', 'A', 'sys-kernel/gentoo-kernel/gentoo-kernel-5.12.8.ebuild'])
deque(['M', 'sys-kernel/vanilla-kernel/Manifest', 'A', 'sys-kernel/vanilla-kernel/vanilla-kernel-5.12.8.ebuild'])
deque(['A', 'virtual/dist-kernel/dist-kernel-5.10.41.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel/Manifest', 'A', 'sys-kernel/gentoo-kernel/gentoo-kernel-5.10.41.ebuild'])
deque(['M', 'sys-kernel/vanilla-kernel/Manifest', 'A', 'sys-kernel/vanilla-kernel/vanilla-kernel-5.10.41.ebuild'])
deque(['A', 'virtual/dist-kernel/dist-kernel-5.4.123.ebuild'])
deque(['M', 'sys-kernel/gentoo-kernel/Manifest', 'A', 'sys-kernel/gentoo-kernel/gentoo-kernel-5.4.123.ebuild'])
deque(['M', 'sys-kernel/vanilla-kernel/Manifest', 'A', 'sys-kernel/vanilla-kernel/vanilla-kernel-5.4.123.ebuild'])
deque(['M', 'profiles/package.mask'])
deque(['M', 'dev-python/sphinxcontrib-github-alt/Manifest', 'A', 'dev-python/sphinxcontrib-github-alt/sphinxcontrib-github-alt-1.2.ebuild'])
deque(['M', 'dev-python/sphinxcontrib-doxylink/metadata.xml'])

Specifically note:

deque(['M', 'sys-kernel/gentoo-kernel-bin/Manifest', 'A', 'sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.12.8.ebuild', 'ble doc generation'])

This seems to come from:

M^@dev-python/sphinxcontrib-doxylink/metadata.xml^@
a407ba50c016
1622233576
Zamarin Arthur <arthurzam@gmail.com>
Michał Górny <mgorny@gentoo.org>
dev-python/sphinxcontrib-doxylink: enable doc generation

Signed-off-by: Zamarin Arthur <arthurzam@gmail.com>
Signed-off-by: Michał Górny <mgorny@gentoo.org>
^@

[mgorny]

I've pushed the relevant commits to https://github.com/mgorny/gentoo as pkgcheck-bug326-origin and pkgcheck-bug326-master branches.

[mgorny]

This is really weird. I've added more prints, and this seems to come from this command:

>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0> ['git', 'log', '--name-status', '--diff-filter=ARMD', '-z', '--pretty=tformat:%n%h%n%ct%n%an <%ae>%n%cn <%ce>%n%B', 'origin/HEAD..HEAD']
[...]
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: '18bd33349963\n'
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: '1622234295\n'
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: 'Michał Górny <mgorny@gentoo.org>\n'
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: 'Michał Górny <mgorny@gentoo.org>\n'
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: 'sys-kernel/gentoo-kernel-bin: Bump to 5.12.8\n'
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: '\n'
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: 'Signed-off-by: Michał Górny <mgorny@gentoo.org>\n'
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: '\x00\n'
>>> <pkgcheck.addons.git.GitLog object at 0x7feabcb31ac0>: 'M\x00sys-kernel/gentoo-kernel-bin/Manifest\x00A\x00sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.12.8.ebuild\x00ble doc generation\n'

However, when I run it manually, the output's fine:

$ git log --name-status --diff-filter=ARMD -z '--pretty=tformat:%n%h%n%ct%n%an <%ae>%n%cn <%ce>%n%B' origin/HEAD..HEAD | less

18bd33349963
1622234295
Michał Górny <mgorny@gentoo.org>
Michał Górny <mgorny@gentoo.org>
sys-kernel/gentoo-kernel-bin: Bump to 5.12.8

Signed-off-by: Michał Górny <mgorny@gentoo.org>
^@
M^@sys-kernel/gentoo-kernel-bin/Manifest^@A^@sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.12.8.ebuild^@
ea6385dd41c7
1622234293
Michał Górny <mgorny@gentoo.org>
Michał Górny <mgorny@gentoo.org>
sys-kernel/gentoo-kernel-bin: Bump to 5.10.41

Signed-off-by: Michał Górny <mgorny@gentoo.org>
^@
M^@sys-kernel/gentoo-kernel-bin/Manifest^@A^@sys-kernel/gentoo-kernel-bin/gentoo-kernel-bin-5.10.41.ebuild^@
[...]

[mgorny]

Also, this isn't a recent regression -- I can reproduce it all the way back to 0.9.7.

I'm wondering if it's because of two git log operations being run in parallel, and if yes, then whether it's Python or git screwing something up. Maybe strace can help somehow...

[mgorny]

Well, what's apparent is that ble doc generation\n is from a separate read() call than the base chunk. Both seem to happen in different threads. If I force -j1, things seem to work, so it seems to be a threading problem.