(question) when is the subsonic server scanned exactly?

[whinette]

Hello,

I frequently tinkers with my library, to improve its tagging and add new albums.
The initial scan is quite long (and I don't have any problem with that), I got this kind of logs for hours:

But when I batch update or add albums (hundred of thems), no scan appears in the logs.

Is it done on a schedule?
Thanks in advance.

[GioF71]

Hello, which version of the subsonic plugin are you using? I have removed that initialization phase since some time now, in favor of run-time caching.
Library scan is not executed by the plugin, it should be always requested through the server (so I understand it's lms in your case).
The "loading" you are seeing has the purpose of retrieving album metadata (or derived from tracks, like that quality badge).
Also if you are running an older version I'd recommend to upgrade. I have done a lot of changes for responsiveness.

[whinette]

I've installed it two days ago, through apt on a debian12.
The repo was added following this documentation: https://www.lesbonscomptes.com/upmpdcli/pages/downloads.html#debian

Package: upmpdcli-subsonic
Version: 1.9.5-1~ppa1~bookworm

[GioF71]

Ok, infact on that version, the initial (and potentially slow) library import (which was NOT a library scan anyway, but it was a data ingestion into the plugin's own database) should not be there anymore. Can you post some logs of application and plugin startup?

[GioF71]

I've installed it two days ago, through apt on a debian12. The repo was added following this documentation: https://www.lesbonscomptes.com/upmpdcli/pages/downloads.html#debian

Package: upmpdcli-subsonic Version: 1.9.5-1ppa1bookworm

Master branch is at version 0.8.6. See here.
You should be at version 0.8.1.
You can easily access newer version using docker if you don't want to compile upmpdcli on your own. See here for a sample docker compose file.

[whinette]

I don't have way to run container on this server, I'll check next weekend (either that or compile the binary).
Startup logs:

^@upmpdcli:~# service upmpdcli restart
^@upmpdcli:~# journalctl -u upmpdcli.service -f
[...]
Jul 27 20:36:30 upmpdcli systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Jul 27 20:36:30 upmpdcli upmpdcli[6951]: :3:../libupnpp/upnpplib.cxx:273::LibUPnP: Using IPV4 192.168.1.157 port 49152 IPV6  port 49152
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: base_url/port: [http://192.168.1.11]:[5082]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: User Agent: [upmpdcli]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: 0$UNKNOWN: getcachedir: me: upmpdcli
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Initial Creation] index [0] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Initial Creation] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Create new table album_metadata_v1] index [1] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Create new table album_metadata_v1] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Create new table kv_cache_v1] index [2] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Create new table kv_cache_v1] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Create new table artist_metadata_v1] index [3] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Create new table artist_metadata_v1] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Altering artist_metadata_v1, adding artist musicbrainz id] index [4] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Altering artist_metadata_v1, adding artist musicbrainz id] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Altering album_metadata_v1, adding album musicbrainz id] index [5] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Altering album_metadata_v1, adding album musicbrainz id] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Altering album_metadata_v1, adding album artist id] index [6] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Altering album_metadata_v1, adding album artist id] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Altering album_metadata_v1, adding artist album count] index [7] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Altering album_metadata_v1, adding artist album count] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Altering album_metadata_v1, adding artist cover art] index [8] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Altering album_metadata_v1, adding artist cover art] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10] -> Examining migration [Altering album_metadata_v1, adding album path] index [9] ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Migration [Altering album_metadata_v1, adding album path] skipped.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Current db version is [10]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Preloading ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Loaded [2023] records from [album_metadata_v1].
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Loaded [517] records from [artist_metadata_v1].
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Finished preloading.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Subsonic [0.8.1] Initializing ...
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: subsonic: getcachedir: me: upmpdcli
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Cache dir for [subsonic] is [/var/cache/upmpdcli/subsonic]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: DB version for [subsonic] is [10]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: check_supports_highest highest not supported [<class 'libsonic.errors.SonicError'>] [Not implemented]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: highest type in getAlbumList supported: [no]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: check_supports_highest highest not supported [<class 'libsonic.errors.SonicError'>] [Not implemented]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Internet Radio stations supported: [no]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: WebServer not available
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Cache directory is not set, cannot allow pruning.
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Subsonic [0.8.1] Initialization success: [True]
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Subsonic running
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: args: --{'cmdtalk:proc': 'browse', 'count': '30', 'offset': '0', 'flag': 'children', 'objid': '0$subsonic$'}--
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: Subsonic Plugin Release 0.8.1
Jul 27 20:36:34 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: subsonic_util.get_starred loading starred ...
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: subsonic_util.get_random_album_list loading first random albums ...
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: show_tag_entries adding tag [TagType.ALBUMS] shown [yes] took [6.477].
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: __favourite_artist_art_retriever selected artist [ar-9466]
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: artist_entry_for_album loaded artist for id [ar-9466] -> [yes]
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: get_artist_art_url_using_albums_by_artist_id select_album_list for [ar-9466] [A-GEAR] full length [18] as main artist only [18]
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: artist_entry_for_album select_album_list len is [18]
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: artist_entry_for_album selected album: [al-12554]
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: favourite_artist_art_retriever fav found: [yes]
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: show_tag_entries adding tag [TagType.ARTISTS] shown [yes] took [0.036].
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: show_tag_entries adding tag [TagType.SONGS] shown [yes] took [0.003].
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: show_tag_entries adding tag [TagType.GENRES] shown [yes] took [0.001].
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: show_tag_entries adding tag [TagType.PLAYLISTS] shown [no] took [0.002].
Jul 27 20:36:40 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: show_tag_entries finished.
Jul 27 20:36:41 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: args: --{'cmdtalk:proc': 'browse', 'count': '30', 'offset': '0', 'flag': 'children', 'objid': '0$subsonic$/eyJuIjogInRhZyIsICJ2IjogImdsYm1zIiwgInJuZCI6ICJ3cnZyb2gifQ=='}--
Jul 27 20:36:41 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: item_identifier name: --tag-- value: --glbms--
Jul 27 20:36:41 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: should serve tag: --glbms--
Jul 27 20:36:41 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: found tag handler for: --TagType.ALBUMS--
Jul 27 20:36:41 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: handler_tag_group_albums loading favorites ...
Jul 27 20:36:41 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: handler_tag_group_albums favorite albums [0] ...
Jul 27 20:36:41 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: handler_tag_group_albums skipping unsupported [TagType.HIGHEST_RATED_ALBUMS]
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: args: --{'cmdtalk:proc': 'browse', 'count': '30', 'offset': '0', 'flag': 'children', 'objid': '0$subsonic$/eyJuIjogInRhZyIsICJ2IjogImdydHN0cyIsICJybmQiOiAiY2lkc2FlIn0='}--
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: item_identifier name: --tag-- value: --grtsts--
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: should serve tag: --grtsts--
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: browse: found tag handler for: --TagType.ARTISTS--
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: handler_tag_group_artists favorite artists count: [32]
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: handler_tag_group_artists fav_artist [ar-9874] [DiGiTAL WiNG]
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: artist_entry_for_album loaded artist for id [ar-9874] -> [yes]
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: get_artist_art_url_using_albums_by_artist_id select_album_list for [ar-9874] [DiGiTAL WiNG] full length [142] as main artist only [138]
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: artist_entry_for_album select_album_list len is [138]
Jul 27 20:36:42 upmpdcli upmpdcli[6986]: CMDTALK: subsonic-app.py: artist_entry_for_album selected album: [al-13300]
^C

[GioF71]

Ok, version 0.8.1 (from the latest upmpdcli release).
Initialization is still there but does not do the old data preloading, it only loades local cache to ram for responsiveness. It's a quick step.
The thing I was referring to has gone away since version 0.6.4, see here and here, that might be very slow.

[whinette]

It's clear, thanks. :)

[GioF71]

Issue transferred to upmpdcli-plugins repository