navidrome / navidrome

🎧☁️ Modern Music Server and Streamer compatible with Subsonic/Airsonic
https://www.navidrome.org
GNU General Public License v3.0
10.36k stars 797 forks source link

[Bug]: Internal server error when call getAlbumInfo2 endpoint for unknown album #2889

Open lilotter45 opened 2 months ago

lilotter45 commented 2 months ago

I confirm that:

Version

0.51.1

Current Behavior

I initially encountered this error while attempting to setup Navidrome as a Subsonic Media Server music provider within Home Assistant's Music Assistant; the library synchronization would fail when a status code = 500 was returned.

Further investigation narrowed this down to a call to the getAlbumInfo2.view api endpoint. It seems to occur when an "Unknown" (meaning an album name that doesn't exist for a particular artist) album is submitted.

I have verified that the api call works for known albums and fails for unknown albums; this is true when making api calls from Music Assistant, Firefox, and Insomnia.

Expected Behavior

A response indicating the lookup failed, including the Subsonic error code (presumably 70 in this case; https://www.subsonic.org/pages/api.jsp#ErrorHandling), allowing the client to handle the error and continue.

Steps To Reproduce

  1. Enable and configure LastFM and Spotify integrations
  2. Run a get request against the getAlbumInfo2.view api endpoint, using the id of a fake album as the provided id. For example: https://music.base.url/rest/getAlbumInfo2.view?u=user&p=password&v=1.16.1&c=myApp&id=178c6e5e29a3cb44f755bb045cbc6854
    • The album in this example is "[Unknown Album]" by Iron Horse
  3. Receive a 500 internal server error response

Environment

- OS: Debian 12 LXC
- Browser: Firefox on OpenSUSE Tumbeweed
- Client: Home Assistant Music Assistant, Firefox (api request), Insomnia

How Navidrome is installed?

Binary (from downloads page)

Configuration

BaseUrl = "https://music.my.tld"
MusicFolder = "/mnt/media/music/Music"
LogLevel = 'DEBUG'
ScanSchedule = "0 0 * * *"
EnableLogRedacting = false
EnableSharing = true
EnableTranscodingConfig = true
Jukebox.Enabled = false
LastFM.Enabled = true
LastFM.ApiKey = "[redacted]"
LastFM.Secret = "[redacted]"
LastFM.Language = "en"
Spotify.ID = "[redacted]"
Spotify.Secret = "[redacted]"

Relevant log output

Mar 03 16:19:14 ct-navidrome navidrome[2612]:  _   _             _     _
Mar 03 16:19:14 ct-navidrome navidrome[2612]: | \ | |           (_)   | |
Mar 03 16:19:14 ct-navidrome navidrome[2612]: |  \| | __ ___   ___  __| |_ __ ___  _ __ ___   ___
Mar 03 16:19:14 ct-navidrome navidrome[2612]: | . ` |/ _` \ \ / / |/ _` | '__/ _ \| '_ ` _ \ / _ \
Mar 03 16:19:14 ct-navidrome navidrome[2612]: | |\  | (_| |\ V /| | (_| | | | (_) | | | | | |  __/
Mar 03 16:19:14 ct-navidrome navidrome[2612]: \_| \_/\__,_| \_/ |_|\__,_|_|  \___/|_| |_| |_|\___|
Mar 03 16:19:14 ct-navidrome navidrome[2612]:                           Version: 0.51.1 (6d253225)
Mar 03 16:19:14 ct-navidrome navidrome[2612]: Loaded configuration from '/var/lib/navidrome/navidrome.toml': &conf.configOptions{
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     ConfigFile:                   "/var/lib/navidrome/navidrome.toml",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     Address:                      "0.0.0.0",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     Port:                         4533,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     UnixSocketPerm:               "0660",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     MusicFolder:                  "/mnt/media/music/Music",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DataFolder:                   ".",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     CacheFolder:                  "cache",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DbPath:                       "navidrome.db?cache=shared&_busy_timeout=15000&_journal_mode=WAL&_foreign_keys=on",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     LogLevel:                     "DEBUG",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     ScanInterval:                 -1,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     ScanSchedule:                 "0 0 * * *",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     SessionTimeout:               86400000000000,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     BaseURL:                      "https://music.my.tld",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     BasePath:                     "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     BaseHost:                     "music.my.tld",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     BaseScheme:                   "https",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     TLSCert:                      "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     TLSKey:                       "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     UILoginBackgroundURL:         "/backgrounds",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     UIWelcomeMessage:             "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     MaxSidebarPlaylists:          100,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableTranscodingConfig:      true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableDownloads:              true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableExternalServices:       true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableMediaFileCoverArt:      true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     TranscodingCacheSize:         "100MB",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     ImageCacheSize:               "100MB",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableArtworkPrecache:        true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     AutoImportPlaylists:          true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     PlaylistsPath:                ".:**/**",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     AutoTranscodeDownload:        false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DefaultDownsamplingFormat:    "opus",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     SearchFullString:             false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     RecentlyAddedByModTime:       false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     PreferSortTags:               false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     IgnoredArticles:              "The El La Los Las Le Les Os As O A",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     IndexGroups:                  "A B C D E F G H I J K L M N O P Q R S T U V W X-Z(XYZ) [Unknown]([)",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     SubsonicArtistParticipations: false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     FFmpegPath:                   "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     MPVPath:                      "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     CoverArtPriority:             "cover.*, folder.*, front.*, embedded, external",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     CoverJpegQuality:             75,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     ArtistArtPriority:            "artist.*, album/artist.*, external",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableGravatar:               false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableFavourites:             true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableStarRating:             true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableUserEditing:            true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableSharing:                true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DefaultDownloadableShare:     false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DefaultTheme:                 "Dark",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DefaultLanguage:              "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DefaultUIVolume:              100,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableReplayGain:             true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableCoverAnimation:         true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     GATrackingID:                 "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     EnableLogRedacting:           false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     AuthRequestLimit:             5,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     AuthWindowLength:             20000000000,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     PasswordEncryptionKey:        "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     ReverseProxyUserHeader:       "Remote-User",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     ReverseProxyWhitelist:        "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     Prometheus:                   conf.prometheusOptions{Enabled:false, MetricsPath:"/metrics"},
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     Scanner:                      conf.scannerOptions{Extractor:"taglib", GenreSeparators:";/,", GroupAlbumReleases:false},
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     Jukebox:                      conf.jukeboxOptions{
Mar 03 16:19:14 ct-navidrome navidrome[2612]:         Enabled: false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:         Devices: {
Mar 03 16:19:14 ct-navidrome navidrome[2612]:         },
Mar 03 16:19:14 ct-navidrome navidrome[2612]:         Default: "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     },
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     Agents:                           "lastfm,spotify",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     LastFM:                           conf.lastfmOptions{Enabled:true, ApiKey:[REDACTED], Secret:[REDACTED], Language:"en"},
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     Spotify:                          conf.spotifyOptions{ID:[REDACTED], Secret:[REDACTED]},
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     ListenBrainz:                     conf.listenBrainzOptions{Enabled:true, BaseURL:"https://api.listenbrainz.org/1/"},
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevLogSourceLine:                 false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevLogLevels:                     {},
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevEnableProfiler:                false,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevAutoCreateAdminPassword:       "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevAutoLoginUsername:             "",
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevActivityPanel:                 true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevSidebarPlaylists:              true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevEnableBufferedScrobble:        true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevShowArtistPage:                true,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevOffsetOptimize:                50000,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevArtworkMaxRequests:            2,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevArtworkThrottleBacklogLimit:   100,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevArtworkThrottleBacklogTimeout: 60000000000,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevArtistInfoTimeToLive:          86400000000000,
Mar 03 16:19:14 ct-navidrome navidrome[2612]:     DevAlbumInfoTimeToLive:           604800000000000,
Mar 03 16:19:14 ct-navidrome navidrome[2612]: }
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Opening DataBase" dbPath="navidrome.db?cache=shared&_busy_timeout=15000&_journal_mode=WAL&_foreign_keys=on" driver=sqlite3
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="goose: no migrations to run. current version: 20240122223340\n"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Starting signaler"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Configuring Media Folder" name="Music Library" path=/mnt/media/music/Music
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Starting scheduler"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Setting Session Timeout" value=24h
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Login rate limit set" requestLimit=5 windowLength=2
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Found ffmpeg" path=/usr/bin/ffmpeg
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Last.fm integration is ENABLED"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="ListenBrainz integration is ENABLED" ListenBrainz.BaseURL="https://api.listenbrainz.org/1/"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Spotify integration is ENABLED"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Mounting Native API routes" path=/api
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Throttling Subsonic getCoverArt endpoint" backlogLimit=100 backlogTimeout=1m maxRequests=2
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Mounting Subsonic API routes" path=/rest
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Throttling public images endpoint" backlogLimit=100 backlogTimeout=1m maxRequests=2
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Mounting Public Endpoints routes" path=/share
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Mounting LastFM Auth routes" path=/api/lastfm
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Mounting ListenBrainz Auth routes" path=/api/listenbrainz
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Mounting Background images routes" path=/backgrounds
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Mounting WebUI routes" path=/app
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Creating Image cache" maxSize="100 MB" path=cache/images
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Loaded cache" dir=cache/images numItems=0
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Finished initializing cache" cache=Image elapsedTime="152.594µs" maxSize=100MB
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Scheduler: start"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Scheduling periodic scan" schedule="0 0 * * *"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Scheduler: added" entry=1 next="2024-03-04 00:00:00 +0000 UTC" now="2024-03-03 16:19:14.733909451 +0000 UTC"
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Creating Transcoding cache" maxSize="100 MB" path=cache/transcoding
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Loaded cache" dir=cache/transcoding numItems=0
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="Finished initializing cache" cache=Transcoding elapsedTime="115.02µs" maxSize=100MB
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=info msg="----> Navidrome server is ready!" address="0.0.0.0:4533" startupTime=12.2ms tlsEnabled=false
Mar 03 16:19:14 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:14Z" level=debug msg="Loaded background images from image service" elapsed=177.3ms total=102
Mar 03 16:19:16 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:16Z" level=debug msg="Executing initial scan"
Mar 03 16:19:16 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:16Z" level=debug msg="Scanning folder" folder=/mnt/media/music/Music lastModifiedSince="2024-03-03 16:18:04.369 +0000 UTC"
Mar 03 16:19:16 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:16Z" level=debug msg="Directory tree loaded from DB" elapsed=47.4ms total=3335
Mar 03 16:19:31 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:31Z" level=debug msg="Finished reading directories from filesystem" path=/mnt/media/music/Music
Mar 03 16:19:31 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:31Z" level=debug msg="Finished deleted folders check" elapsed="556.513µs" total=0
Mar 03 16:19:31 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:31Z" level=debug msg="No changes found in Music Folder" elapsed=14.94s folder=/mnt/media/music/Music
Mar 03 16:19:31 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:31Z" level=debug msg="Finished initial scan"

[SUCCESSFULL REQUESTS]

Mar 03 16:19:46 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:46Z" level=debug msg="API: New request /rest/getAlbumInfo2.view" client=myApp requestId=ct-navidrome/wIhvuuQFLO-000001 username=mass version=1.16.1
Mar 03 16:19:46 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:46Z" level=debug msg="AlbumInfo not cached. Retrieving it now" id=6b585a2c3b7f8959fd86f70e7b7322a5 name="Save Me, San Francisco" requestId=ct-navidrome/wIhvuuQFLO-000001 updatedAt="0001-01-01 00:00:00 +0000 UTC" username=mass
Mar 03 16:19:47 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:47Z" level=debug msg="Got Album Info" agent=lastfm album="Save Me, San Francisco" artist=Train elapsed=871.9ms mbid= requestId=ct-navidrome/wIhvuuQFLO-000001 username=mass
Mar 03 16:19:47 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:47Z" level=debug msg="Found expired cached AlbumInfo, refreshing in the background" name="Save Me, San Francisco" updatedAt="2024-03-03 16:19:47.576155527 +0000 UTC m=+32.855286610"
Mar 03 16:19:47 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:47Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbumInfo2.view requestId=ct-navidrome/wIhvuuQFLO-000001 status=OK username=mass
Mar 03 16:19:47 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:47Z" level=debug msg="HTTP: GET http://music.my.tld/rest/getAlbumInfo2.view?u=mass&p=password&v=1.16.1&c=myApp&id=6b585a2c3b7f8959fd86f70e7b7322a5" elapsedTime=874.5ms httpStatus=200 remoteAddr=10.77.75.189 requestId=ct-navidrome/wIhvuuQFLO-000001 responseSize=1716 userAgent=insomnia/8.6.1
Mar 03 16:19:47 ct-navidrome navidrome[2612]: time="2024-03-03T16:19:47Z" level=debug msg="Got Album Info" agent=lastfm album="Save Me, San Francisco" artist=Train elapsed="133.798µs" mbid=
Mar 03 16:20:03 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:03Z" level=debug msg="API: New request /rest/getArtists.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000002 username=mass version=1.16.1
Mar 03 16:20:03 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:03Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000002 type=python-requests username=mass
Mar 03 16:20:03 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:03Z" level=debug msg="API: Successful response" endpoint=/rest/getArtists.view requestId=ct-navidrome/wIhvuuQFLO-000002 status=OK username=mass
Mar 03 16:20:03 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:03Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getArtists.view" elapsedTime=69.3ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000002 responseSize=556184 userAgent=python-requests/2.31.0
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: New request /rest/getAlbumList2.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000003 username=mass version=1.16.1
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000003 type=python-requests username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbumList2.view requestId=ct-navidrome/wIhvuuQFLO-000003 status=OK username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getAlbumList2.view" elapsedTime=21.7ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000003 responseSize=270410 userAgent=python-requests/2.31.0
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: New request /rest/getAlbum.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000004 username=mass version=1.16.1
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000004 type=python-requests username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbum.view requestId=ct-navidrome/wIhvuuQFLO-000004 status=OK username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getAlbum.view" elapsedTime=1.5ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000004 responseSize=1450 userAgent=python-requests/2.31.0
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: New request /rest/getAlbumInfo2.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000005 username=mass version=1.16.1
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000005 type=python-requests username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="AlbumInfo not cached. Retrieving it now" id=7af81d5daaca08006ce997754d1dd391 name="Wild-Eyed Southern Boys" requestId=ct-navidrome/wIhvuuQFLO-000005 updatedAt="0001-01-01 00:00:00 +0000 UTC" username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Got Album Info" agent=lastfm album="Wild-Eyed Southern Boys" artist=".38 Special" elapsed=97.6ms mbid= requestId=ct-navidrome/wIhvuuQFLO-000005 username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found expired cached AlbumInfo, refreshing in the background" name="Wild-Eyed Southern Boys" updatedAt="2024-03-03 16:20:05.537179121 +0000 UTC m=+50.816310203"
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbumInfo2.view requestId=ct-navidrome/wIhvuuQFLO-000005 status=OK username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getAlbumInfo2.view" elapsedTime=99.7ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000005 responseSize=1633 userAgent=python-requests/2.31.0
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Got Album Info" agent=lastfm album="Wild-Eyed Southern Boys" artist=".38 Special" elapsed="112.649µs" mbid=
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: New request /rest/getAlbum.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000006 username=mass version=1.16.1
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000006 type=python-requests username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbum.view requestId=ct-navidrome/wIhvuuQFLO-000006 status=OK username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getAlbum.view" elapsedTime=1ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000006 responseSize=1450 userAgent=python-requests/2.31.0
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: New request /rest/getAlbum.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000007 username=mass version=1.16.1
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000007 type=python-requests username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbum.view requestId=ct-navidrome/wIhvuuQFLO-000007 status=OK username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getAlbum.view" elapsedTime=1.9ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000007 responseSize=14296 userAgent=python-requests/2.31.0
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: New request /rest/getAlbumInfo2.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000008 username=mass version=1.16.1
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000008 type=python-requests username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="AlbumInfo not cached. Retrieving it now" id=10507f5b2510a5fab5b4cad4226a189b name=112 requestId=ct-navidrome/wIhvuuQFLO-000008 updatedAt="0001-01-01 00:00:00 +0000 UTC" username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Got Album Info" agent=lastfm album=112 artist=112 elapsed=140.3ms mbid= requestId=ct-navidrome/wIhvuuQFLO-000008 username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found expired cached AlbumInfo, refreshing in the background" name=112 updatedAt="2024-03-03 16:20:05.81582312 +0000 UTC m=+51.094954200"
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbumInfo2.view requestId=ct-navidrome/wIhvuuQFLO-000008 status=OK username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getAlbumInfo2.view" elapsedTime=142.3ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000008 responseSize=893 userAgent=python-requests/2.31.0
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: New request /rest/getAlbum.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000009 username=mass version=1.16.1
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000009 type=python-requests username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbum.view requestId=ct-navidrome/wIhvuuQFLO-000009 status=OK username=mass
Mar 03 16:20:05 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:05Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getAlbum.view" elapsedTime=1.9ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000009 responseSize=14296 userAgent=python-requests/2.31.0
Mar 03 16:20:06 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:06Z" level=debug msg="API: New request /rest/getAlbum.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000010 username=mass version=1.16.1
Mar 03 16:20:06 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:06Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000010 type=python-requests username=mass
Mar 03 16:20:06 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:06Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbum.view requestId=ct-navidrome/wIhvuuQFLO-000010 status=OK username=mass
Mar 03 16:20:06 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:06Z" level=debug msg="HTTP: POST http://music.my.tld/rest/getAlbum.view" elapsedTime=1.3ms httpStatus=200 remoteAddr=10.77.30.186 requestId=ct-navidrome/wIhvuuQFLO-000010 responseSize=1170 userAgent=python-requests/2.31.0
Mar 03 16:20:06 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:06Z" level=debug msg="API: New request /rest/getAlbumInfo2.view" client="Music Assistant" requestId=ct-navidrome/wIhvuuQFLO-000011 username=mass version=1.16.1
Mar 03 16:20:06 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:06Z" level=debug msg="Found matching player" client="Music Assistant" id=fb601a4f-3005-453a-8a8a-672e66d0006c requestId=ct-navidrome/wIhvuuQFLO-000011 type=python-requests username=mass

[FAILED REQUEST]

Mar 03 16:20:06 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:06Z" level=debug msg="AlbumInfo not cached. Retrieving it now" id=f6f9c3d4163c59f23688206e0219dbdd name="[Unknown Album]" requestId=ct-navidrome/wIhvuuQFLO-000011 updatedAt="0001-01-01 00:00:00 +0000 UTC" username=mass
Mar 03 16:20:06 ct-navidrome navidrome[2612]:  panic: value method time.Time.String called using nil *Time pointer
Mar 03 16:20:06 ct-navidrome navidrome[2612]:  
Mar 03 16:20:06 ct-navidrome navidrome[2612]:  -> time.(*Time).String
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     <autogenerated>:1 +0x3a
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/log.addFields
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/log/log.go:270
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/log.parseArgs
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/log/log.go:234
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/log.log
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/log/log.go:192
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/log.Debug
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/log/log.go:181
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/core.(*externalMetadata).UpdateAlbumInfo
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/core/external_metadata.go:104
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server/subsonic.(*Router).GetAlbumInfo
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/subsonic/browsing.go:194
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server/subsonic.(*Router).routes.func2.h.func11
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/subsonic/api.go:206
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server/subsonic.hr.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/subsonic/api.go:213
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server/subsonic.(*Router).routes.func2.getPlayer.func1.1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/subsonic/middlewares.go:174
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5.(*ChainHandler).ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/chain.go:31
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5.(*Mux).routeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/mux.go:443
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server/subsonic.(*Router).routes.authenticate.func17.1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/subsonic/middlewares.go:107
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server/subsonic.checkRequiredParameters.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/subsonic/middlewares.go:67
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server/subsonic.postFormToQueryParams.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/subsonic/middlewares.go:41
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5.(*Mux).ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/mux.go:73
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5.(*Mux).Mount.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/mux.go:315
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.requestLogger.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/middlewares.go:33
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.jwtVerifier.jwtVerifier.Verify.func1.func2
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/jwtauth/v5@v5.3.0/jwtauth.go:78
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.authHeaderMapper.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/auth.go:181
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.loggerInjector.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/middlewares.go:64
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5/middleware.(*Compressor).Handler-fm.(*Compressor).Handler.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/middleware/compress.go:209
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.clientUniqueIDMiddleware.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/middlewares.go:157
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.serverAddressMiddleware.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/middlewares.go:185
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.(*Server).initRoutes.robotsTXT.func4.1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /github/workspace/server/middlewares.go:75
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.(*Server).initRoutes.Heartbeat.func3.1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/middleware/heartbeat.go:21
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5/middleware.Recoverer.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/middleware/recoverer.go:45
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/navidrome/navidrome/server.realIPMiddleware.RealIP.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/middleware/realip.go:36
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5/middleware.RequestID.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/middleware/request_id.go:76
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/cors.(*Cors).Handler-fm.(*Cors).Handler.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/cors@v1.2.1/cors.go:228
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/unrolled/secure.(*Secure).Handler-fm.(*Secure).Handler.func1
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/unrolled/secure@v1.14.0/secure.go:198
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5.(*ChainHandler).ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/chain.go:31
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5.(*Mux).routeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/mux.go:443
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.HandlerFunc.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2136
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     github.com/go-chi/chi/v5.(*Mux).ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /go/pkg/mod/github.com/go-chi/chi/v5@v5.0.11/mux.go:90
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.serverHandler.ServeHTTP
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2938
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     net/http.(*conn).serve
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:2009
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     created by net/http.(*Server).Serve in goroutine 38
Mar 03 16:20:06 ct-navidrome navidrome[2612]:       /usr/local/go/src/net/http/server.go:3086
Mar 03 16:20:06 ct-navidrome navidrome[2612]:     
Mar 03 16:20:10 ct-navidrome navidrome[2612]: time="2024-03-03T16:20:10Z" level=debug msg="Got Album Info" agent=lastfm album=112 artist=112 elapsed="118.769µs" mbid=
Mar 03 16:21:24 ct-navidrome navidrome[2612]: time="2024-03-03T16:21:24Z" level=debug msg="API: New request /rest/getAlbumInfo2.view" client=myApp requestId=ct-navidrome/wIhvuuQFLO-000012 username=mass version=1.16.1
Mar 03 16:21:24 ct-navidrome navidrome[2612]: time="2024-03-03T16:21:24Z" level=debug msg="API: Successful response" endpoint=/rest/getAlbumInfo2.view requestId=ct-navidrome/wIhvuuQFLO-000012 status=OK username=mass
Mar 03 16:21:24 ct-navidrome navidrome[2612]: time="2024-03-03T16:21:24Z" level=debug msg="HTTP: GET http://music.my.tld/rest/getAlbumInfo2.view?u=mass&p=password&v=1.16.1&c=myApp&id=6b585a2c3b7f8959fd86f70e7b7322a5" elapsedTime=1.4ms httpStatus=200 remoteAddr=10.77.75.189 requestId=ct-navidrome/wIhvuuQFLO-000012 responseSize=1716 userAgent=insomnia/8.6.1

Anything else?

No response

Code of Conduct

arren-ru commented 2 months ago

Can confirm that also. I discovered the same errors while accessing the /rest/getAlbumInfo path.

georgebarnett commented 1 month ago

I have been hitting this. I downgraded to 0.51.0 and this does not occur.

deluan commented 1 month ago

Thanks for the report. This was fixed in 5abe1567774fc54f6dbad085bb1ddaf19000e0dd but not released yet. Can you try with the develop build and let me know if that works?

I'm planning to release a new bug-fix version soon.