audio delay

[AxelBohm]

I recently switched from a 2012 macbook to the new M1 and suddenly it takes at least 2 seconds (sometimes even more) to start reading the card out loud. My anki version is 2.1.35 on both machines and they are synched as well. Does anybody know what could be causing this?

[kelciour]

It might happen if you use on-the-fly TTS and the AwesomeTTS couldn't find the audio file in the cache folder. But once the audio was generated, it will be stored in the cache folder and the next time, if you review the same card again, there should be no delay.

By default it's set to last for 365 days. At the moment the cache folder is stored at 814349176\awesometts\.cache and always will be cleared out on the add-on update. I'll fix it someday. As far as I know, the latest version of https://ankiweb.net/shared/info/1436550454 doesn't have this issue anymore.

Otherwise, the issue was caused probably by another add-on or mpv.

Maybe try to start Anki and hold down the Shift key to disable all add-ons, then review a few cards to see if the delay is still present or not.

Maybe import this deck - https://ankiweb.net/shared/info/427804922. If you review it, there should be no delay. If the delay is still present, it probably means that mpv, that Anki uses to play all sound files, is a culprit. In this case, try installing the latest Anki version (maybe temporarily) to see if the issue is still present. If it doesn't help, open Anki, use the following code in the debug console, and review a few cards.

https://docs.ankiweb.net/misc.html#debug-console

import os
from aqt import mw
from aqt.sound import mpvManager
logfile = os.path.join(mw.pm.base, 'mpv.debug.log.txt')
path = os.path.expanduser(logfile)
with open(os.path.join(mw.pm.base, 'mpv.conf'), 'a') as f:
    f.write('log-file={}\n'.format(path))
print('log-file:', mpvManager.get_property('log-file'))
mpvManager.shutdown()
print('log-file:', mpvManager.get_property('log-file'))

Maybe the log file will provide some useful information

[AxelBohm]

Hey @kelciour , thanks for quick response. The issue doesn't seem to be due to problems with cache:

• even if I look at the same card twice in the same session the lag persists
• on the old laptop there is generally no lag even for completely new cards

I tried the classical music set and there is no delay there so the problem seems to not lie with mpv either.

Lastly, I started anki and held down the shift key to deactivate all plugins but the delay persisted.

I also tried starting Anki in debug mode and got the following output:

mpv too old for key rebinding
Qt WebEngine resources not found at . Trying parent directory...
Qt WebEngine resources not found at /Applications/Anki.app/Contents/MacOS/PyQt5/Qt. Trying application directory...
Installed Qt WebEngine locales directory not found at location /qtwebengine_locales. Trying application directory...
qt.qpa.fonts: Populating font family aliases took 340 ms. Replace uses of missing font family "Segoe UI" with one that exists to avoid this cost.

And after closing anki there was some additional output:

[35517:259:1121/161329.948393:ERROR:gl_bindings_autogen_gl.cc(14644)] Trying to call glFlush without current GL context
addons_dialog_will_delete_addon is not a hook yet
gettext _() is deprecated: &View
gettext _() is deprecated: &Zoom
gettext _() is deprecated: Zoom &In
gettext _() is deprecated: Zoom &Out
gettext _() is deprecated: &Reset
deckDueTree() is deprecated; use decks.deck_tree() for a tree without counts, or sched.deck_due_tree()
gettext _() is deprecated: New Cards
gettext _() is deprecated: Learn
gettext _() is deprecated: To Review
gettext _() is deprecated: Due
gettext _() is deprecated: Total
gettext _() is deprecated: Average
gettext _() is deprecated: %.01f
gettext _() is deprecated: Cards
gettext _() is deprecated: Minutes
ngettext() is deprecated: %s minutes.
gettext _() is deprecated: More
conf key heatmap should be fetched with col.get_config(), and saved with col.set_config()
conf key heatmap should be fetched with col.get_config(), and saved with col.set_config()
named arguments in queries will go away in the future: 
SELECT
STRFTIME('%s', 'now', 'localtime', 'start of day') + (due - :today) * 86400
AS day, -COUNT() -- negative to support heatmap legend
FROM cards
WHERE did IN (1631863820555,1631863820621,1631863822000,1631863819672,1631863822282,1631863819637,1631863820028,1631863819673,1631863821279,1631863819997,1631863820976,1631863820027,1631863819840,1631863820769,1631863820225,1631863821477,1631863820115,1631863821629,1635791626876,1631863819646,1631863819841,1631892183331,1631863821409,1631863819638,1631863820562,1631863821483,1631863820185,1631863821569,1631863819764,1631863819770,1,1631863819639,1631863819919,1631863819659,1631863819710,1631863820469,1631863820505,1631863821192,1631863820068,1631863819636,1631863819771,1631863820579,1631863821370,1631863821487,1631863819644,1631863821338,1631863820424,1631863819647,1631863819649,1631863819662,1631863821042,1631863820712,1631863821339,1631863820186,1631863820561,1631863821297,1631863822073,1631863819824,1631863819642,1631863819648,1631863820116,1631863819656,1631863819657,1631863820642,1631863821191,1631863819823,1631863819643,1631863819651,1631863819658,1631863819876) AND queue IN (2,3)
 AND day >= 1637452800
GROUP BY day ORDER BY day
conf key imgocc should be fetched with col.get_config(), and saved with col.set_config()
conf key imgocc should be fetched with col.get_config(), and saved with col.set_config()
conf key imgocc should be fetched with col.get_config(), and saved with col.set_config()
deckDueTree() is deprecated; use decks.deck_tree() for a tree without counts, or sched.deck_due_tree()
gettext _() is deprecated: New Cards
gettext _() is deprecated: Learn
gettext _() is deprecated: To Review
gettext _() is deprecated: Due
gettext _() is deprecated: Total
gettext _() is deprecated: Average
gettext _() is deprecated: %.01f
gettext _() is deprecated: Cards
gettext _() is deprecated: Minutes
ngettext() is deprecated: %s minutes.
gettext _() is deprecated: More
named arguments in queries will go away in the future: 
SELECT
STRFTIME('%s', 'now', 'localtime', 'start of day') + (due - :today) * 86400
AS day, -COUNT() -- negative to support heatmap legend
FROM cards
WHERE did IN (1631863819638,1,1631863819876,1631863819658,1631863820225,1631863820621,1631863821279,1631863819710,1631863820561,1631863821487,1631863820505,1631863821192,1631863819659,1631863819636,1631863819919,1631863819997,1631863820028,1631863821297,1631863820579,1631863819646,1631863822073,1631863820562,1631863819841,1631863821629,1631863822282,1631863819639,1631863819644,1631863820712,1631863819840,1631863819656,1631863821477,1631863820186,1631892183331,1631863819648,1631863820027,1631863819649,1631863820976,1631863820185,1631863820555,1631863819823,1631863820068,1631863819662,1631863819770,1631863820116,1631863821409,1635791626876,1631863819764,1631863819647,1631863821042,1631863819657,1631863821191,1631863819642,1631863821569,1631863820115,1631863819771,1631863819673,1631863820424,1631863820769,1631863821339,1631863819824,1631863821483,1631863822000,1631863819643,1631863820642,1631863819672,1631863819637,1631863821338,1631863819651,1631863820469,1631863821370) AND queue IN (2,3)
 AND day >= 1637452800
GROUP BY day ORDER BY day
gettext _() is deprecated: Mature
gettext _() is deprecated: Young
gettext _() is deprecated: Unseen
gettext _() is deprecated: Suspended
gettext _() is deprecated: Total
gettext _() is deprecated: Learned
gettext _() is deprecated: Unlearned
gettext _() is deprecated: New
gettext _() is deprecated: Learning
gettext _() is deprecated: Review
gettext _() is deprecated: Done in
gettext _() is deprecated: Study Now
named arguments in queries will go away in the future: 
SELECT
STRFTIME('%s', 'now', 'localtime', 'start of day') + (due - :today) * 86400
AS day, -COUNT() -- negative to support heatmap legend
FROM cards
WHERE did IN (1631863819636,1631863822282,1631863819659,1631863819642,1631863819643,1631863819649,1631863819646,1631863819647,1631863819648,1631863821569,1631863821629,1631863821487,1631863819651,1631863819662,1631863819644,1631863820579,1631863819637,1631863819823,1631863819997,1631863819824,1631863820424,1631863819638,1631863819639,1631863819919,1631863819876,1631863821370,1631863819672,1631863819710,1631863819673,1631863819770,1631863819771,1631863820469,1631863820115,1631863820116,1631863820505,1631863820621,1631863820555,1631863819840,1631863819841,1631863821279,1631863821297,1631863821483,1631863821338,1631863821477,1631863821339,1631863820561,1631863820562,1631863820976,1631863820769,1631863820642,1631863820712,1631863821042,1631863821191,1631863821192,1631863822000,1631863822073,1631863821409,1631863820185,1631863820225,1631863820186,1631863819656,1631863819764,1631863819657,1631863819658,1631863820027,1631863820068,1631863820028) AND queue IN (2,3)
 AND day >= 1637452800
GROUP BY day ORDER BY day
legacy _anki/overview.css remapped to _anki/css/overview.css
legacy _anki/jquery.js remapped to _anki/js/js/vendor/jquery.js
legacy _anki/overview.js remapped to _anki/js/overview.js
Not found: '_anki/jquery.js'
legacy _anki/jquery.js remapped to _anki/js/js/vendor/jquery.js
Not found: '_anki/jquery.js'
JS error /_anki/overview.js:4 Uncaught ReferenceError: $ is not defined
JS error :438 Uncaught ReferenceError: $ is not defined
.fields() is obsolete, use .note() or .card()
.fields() is obsolete, use .note() or .card()
.fields() is obsolete, use .note() or .card()
.fields() is obsolete, use .note() or .card()
.fields() is obsolete, use .note() or .card()
.fields() is obsolete, use .note() or .card()
.fields() is obsolete, use .note() or .card()
stripSounds() deprecated
.fields() is obsolete, use .note() or .card()

[kelciour]

Maybe generate a log file for mpv to see how much time it takes to start playing the audio file.

Use the following code in the debug console to create a log file for mpv, then review a card, then press R or click on a sound icon to repeat the audio, I assume there will be a delay, and look at the log file.

https://docs.ankiweb.net/misc.html#debug-console

import os
from aqt import mw
from aqt.sound import mpvManager
logfile = os.path.join(mw.pm.base, 'mpv.debug.log.txt')
path = os.path.expanduser(logfile)
with open(os.path.join(mw.pm.base, 'mpv.conf'), 'a') as f:
    f.write('log-file={}\n'.format(path))
print('log-file:', mpvManager.get_property('log-file'))
mpvManager.shutdown()
print('log-file:', mpvManager.get_property('log-file'))

The last lines will contain something like

[ 181.461][d][cplayer] Run command: loadfile, flags=64, args=[url="C:\\Users\\...\\voluminous.mp3", flags="replace", options="pause=no"]
...
[ 181.514][v][cplayer] starting audio playback
...
[ 182.826][v][cplayer] finished playback, success (reason 0)

In this case, it took about 0.05 seconds for a playback to start and 1.31 seconds to finish.

In your case, maybe mpv doesn't like the audio file for some reason and it'll be 1-2 seconds, but maybe some log lines in between will give a clue where mpv is being slow.

If it's good, maybe locate the audio file in the collection.media folder and open it with Audacity, just to check that there's no silince in the beginning.

If you use Bluetooth headphones, maybe review a card without them, with your wired headphones or speakers.