+3
-3
cmd/main.go
+3
-3
cmd/main.go
···
108
lastfmInterval = 30 * time.Second
109
}
110
111
-
if err := spotifyService.LoadAllUsers(); err != nil {
112
-
log.Printf("Warning: Failed to preload Spotify users: %v", err)
113
-
}
114
go spotifyService.StartListeningTracker(trackerInterval)
115
116
go lastfmService.StartListeningTracker(lastfmInterval)
···
108
lastfmInterval = 30 * time.Second
109
}
110
111
+
//if err := spotifyService.LoadAllUsers(); err != nil {
112
+
// log.Printf("Warning: Failed to preload Spotify users: %v", err)
113
+
//}
114
go spotifyService.StartListeningTracker(trackerInterval)
115
116
go lastfmService.StartListeningTracker(lastfmInterval)
+9
-7
oauth/oauth_manager.go
+9
-7
oauth/oauth_manager.go
···
15
services map[string]AuthService
16
sessionManager *session.SessionManager
17
mu sync.RWMutex
18
}
19
20
func NewOAuthServiceManager(sessionManager *session.SessionManager) *OAuthServiceManager {
21
return &OAuthServiceManager{
22
services: make(map[string]AuthService),
23
sessionManager: sessionManager,
24
}
25
}
26
···
29
m.mu.Lock()
30
defer m.mu.Unlock()
31
m.services[name] = service
32
-
log.Printf("Registered auth service: %s", name)
33
}
34
35
// get an AuthService by registered name
···
51
return
52
}
53
54
-
log.Printf("Auth service '%s' not found for login request", serviceName)
55
http.Error(w, fmt.Sprintf("Auth service '%s' not found", serviceName), http.StatusNotFound)
56
}
57
}
···
62
service, exists := m.services[serviceName]
63
m.mu.RUnlock()
64
65
-
log.Printf("Logging in with service %s", serviceName)
66
67
if !exists {
68
-
log.Printf("Auth service '%s' not found for callback request", serviceName)
69
http.Error(w, fmt.Sprintf("OAuth service '%s' not found", serviceName), http.StatusNotFound)
70
return
71
}
···
73
userID, err := service.HandleCallback(w, r)
74
75
if err != nil {
76
-
log.Printf("Error handling callback for service '%s': %v", serviceName, err)
77
http.Error(w, fmt.Sprintf("Error handling callback for service '%s'", serviceName), http.StatusInternalServerError)
78
return
79
}
···
83
84
m.sessionManager.SetSessionCookie(w, session)
85
86
-
log.Printf("Created session for user %d via service %s", userID, serviceName)
87
88
http.Redirect(w, r, "/", http.StatusSeeOther)
89
} else {
90
-
log.Printf("Callback for service '%s' did not result in a valid user ID.", serviceName)
91
// todo: redirect to an error page
92
// right now this just redirects home but we don't want this behaviour ideally
93
http.Redirect(w, r, "/", http.StatusSeeOther)
···
15
services map[string]AuthService
16
sessionManager *session.SessionManager
17
mu sync.RWMutex
18
+
logger *log.Logger
19
}
20
21
func NewOAuthServiceManager(sessionManager *session.SessionManager) *OAuthServiceManager {
22
return &OAuthServiceManager{
23
services: make(map[string]AuthService),
24
sessionManager: sessionManager,
25
+
logger: log.New(log.Writer(), "oauth: ", log.LstdFlags|log.Lmsgprefix),
26
}
27
}
28
···
31
m.mu.Lock()
32
defer m.mu.Unlock()
33
m.services[name] = service
34
+
m.logger.Printf("Registered auth service: %s", name)
35
}
36
37
// get an AuthService by registered name
···
53
return
54
}
55
56
+
m.logger.Printf("Auth service '%s' not found for login request", serviceName)
57
http.Error(w, fmt.Sprintf("Auth service '%s' not found", serviceName), http.StatusNotFound)
58
}
59
}
···
64
service, exists := m.services[serviceName]
65
m.mu.RUnlock()
66
67
+
m.logger.Printf("Logging in with service %s", serviceName)
68
69
if !exists {
70
+
m.logger.Printf("Auth service '%s' not found for callback request", serviceName)
71
http.Error(w, fmt.Sprintf("OAuth service '%s' not found", serviceName), http.StatusNotFound)
72
return
73
}
···
75
userID, err := service.HandleCallback(w, r)
76
77
if err != nil {
78
+
m.logger.Printf("Error handling callback for service '%s': %v", serviceName, err)
79
http.Error(w, fmt.Sprintf("Error handling callback for service '%s'", serviceName), http.StatusInternalServerError)
80
return
81
}
···
85
86
m.sessionManager.SetSessionCookie(w, session)
87
88
+
m.logger.Printf("Created session for user %d via service %s", userID, serviceName)
89
90
http.Redirect(w, r, "/", http.StatusSeeOther)
91
} else {
92
+
m.logger.Printf("Callback for service '%s' did not result in a valid user ID.", serviceName)
93
// todo: redirect to an error page
94
// right now this just redirects home but we don't want this behaviour ideally
95
http.Redirect(w, r, "/", http.StatusSeeOther)
+45
-40
service/lastfm/lastfm.go
+45
-40
service/lastfm/lastfm.go
···
9
"log"
10
"net/http"
11
"net/url"
12
"strconv"
13
"sync"
14
"time"
···
40
atprotoService *atprotoauth.ATprotoAuthService
41
lastSeenNowPlaying map[string]Track
42
mu sync.Mutex
43
}
44
45
func NewLastFMService(db *db.DB, apiKey string, musicBrainzService *musicbrainz.MusicBrainzService, atprotoService *atprotoauth.ATprotoAuthService) *LastFMService {
46
return &LastFMService{
47
db: db,
48
httpClient: &http.Client{
···
56
musicBrainzService: musicBrainzService,
57
lastSeenNowPlaying: make(map[string]Track),
58
mu: sync.Mutex{},
59
}
60
}
61
62
func (l *LastFMService) loadUsernames() error {
63
u, err := l.db.GetAllUsersWithLastFM()
64
if err != nil {
65
-
log.Printf("Error loading users with Last.fm from DB: %v", err)
66
return fmt.Errorf("failed to load users from database: %w", err)
67
}
68
usernames := make([]string, len(u))
···
71
if user.LastFMUsername != nil { // Check if the username is set
72
usernames[i] = *user.LastFMUsername
73
} else {
74
-
log.Printf("User ID %d has Last.fm enabled but no username set", user.ID)
75
}
76
}
77
···
84
}
85
86
l.Usernames = filteredUsernames
87
-
log.Printf("Loaded %d Last.fm usernames", len(l.Usernames))
88
89
return nil
90
}
···
113
return nil, fmt.Errorf("failed to create request for %s: %w", username, err)
114
}
115
116
-
log.Printf("Fetching recent tracks for user: %s", username)
117
resp, err := l.httpClient.Do(req)
118
if err != nil {
119
return nil, fmt.Errorf("failed to fetch recent tracks for %s: %w", username, err)
···
134
}
135
if err := json.Unmarshal(bodyBytes, &recentTracksResp); err != nil {
136
// Log the body content that failed to decode
137
-
log.Printf("Failed to decode response body for %s: %s", username, string(bodyBytes))
138
return nil, fmt.Errorf("failed to decode response for %s: %w", username, err)
139
}
140
141
if len(recentTracksResp.RecentTracks.Tracks) > 0 {
142
-
log.Printf("Fetched %d tracks for %s. Most recent: %s - %s",
143
len(recentTracksResp.RecentTracks.Tracks),
144
username,
145
recentTracksResp.RecentTracks.Tracks[0].Artist.Text,
146
recentTracksResp.RecentTracks.Tracks[0].Name)
147
} else {
148
-
log.Printf("No recent tracks found for %s", username)
149
}
150
151
return &recentTracksResp, nil
···
153
154
func (l *LastFMService) StartListeningTracker(interval time.Duration) {
155
if err := l.loadUsernames(); err != nil {
156
-
log.Printf("Failed to perform initial username load: %v", err)
157
// Decide if we should proceed without initial load or return error
158
}
159
160
if len(l.Usernames) == 0 {
161
-
log.Println("No Last.fm users configured. Tracker will run but fetch cycles will be skipped until users are added.")
162
} else {
163
-
log.Printf("Found %d Last.fm users.", len(l.Usernames))
164
}
165
166
ticker := time.NewTicker(interval)
···
169
if len(l.Usernames) > 0 {
170
l.fetchAllUserTracks(context.Background())
171
} else {
172
-
log.Println("Skipping initial fetch cycle as no users are configured.")
173
}
174
175
for {
···
177
case <-ticker.C:
178
// refresh usernames periodically from db
179
if err := l.loadUsernames(); err != nil {
180
-
log.Printf("Error reloading usernames in ticker: %v", err)
181
// Continue ticker loop even if reload fails? Or log and potentially stop?
182
continue // Continue for now
183
}
184
if len(l.Usernames) > 0 {
185
l.fetchAllUserTracks(context.Background())
186
} else {
187
-
log.Println("No Last.fm users configured. Skipping fetch cycle.")
188
}
189
// TODO: Implement graceful shutdown using context cancellation
190
// case <-ctx.Done():
191
-
// log.Println("Stopping Last.fm listening tracker.")
192
// ticker.Stop()
193
// return
194
}
195
}
196
}()
197
198
-
log.Printf("Last.fm Listening Tracker started with interval %v", interval)
199
}
200
201
// fetchAllUserTracks iterates through users and fetches their tracks.
202
func (l *LastFMService) fetchAllUserTracks(ctx context.Context) {
203
-
log.Printf("Starting fetch cycle for %d users...", len(l.Usernames))
204
var wg sync.WaitGroup // Use WaitGroup to fetch concurrently (optional)
205
fetchErrors := make(chan error, len(l.Usernames)) // Channel for errors
206
207
for _, username := range l.Usernames {
208
if ctx.Err() != nil {
209
-
log.Printf("Context cancelled before starting fetch for user %s.", username)
210
break // Exit loop if context is cancelled
211
}
212
···
214
go func(uname string) { // Launch fetch and process in a goroutine per user
215
defer wg.Done()
216
if ctx.Err() != nil {
217
-
log.Printf("Context cancelled during fetch cycle for user %s.", uname)
218
return // Exit goroutine if context is cancelled
219
}
220
···
223
const fetchLimit = 5
224
recentTracks, err := l.getRecentTracks(ctx, uname, fetchLimit)
225
if err != nil {
226
-
log.Printf("Error fetching tracks for %s: %v", uname, err)
227
fetchErrors <- fmt.Errorf("fetch failed for %s: %w", uname, err) // Report error
228
return
229
}
230
231
if recentTracks == nil || len(recentTracks.RecentTracks.Tracks) == 0 {
232
-
log.Printf("No tracks returned for user %s", uname)
233
return
234
}
235
236
// Process the fetched tracks
237
if err := l.processTracks(ctx, uname, recentTracks.RecentTracks.Tracks); err != nil {
238
-
log.Printf("Error processing tracks for %s: %v", uname, err)
239
fetchErrors <- fmt.Errorf("process failed for %s: %w", uname, err) // Report error
240
}
241
}(username)
···
247
// Log any errors that occurred during the fetch cycle
248
errorCount := 0
249
for err := range fetchErrors {
250
-
log.Printf("Fetch cycle error: %v", err)
251
errorCount++
252
}
253
254
if errorCount > 0 {
255
-
log.Printf("Finished fetch cycle with %d errors.", errorCount)
256
} else {
257
-
log.Println("Finished fetch cycle successfully.")
258
}
259
}
260
···
274
}
275
276
if lastKnownTimestamp == nil {
277
-
log.Printf("no previous scrobble timestamp found for user %s. processing latest track.", username)
278
} else {
279
-
log.Printf("last known scrobble for %s was at %s", username, lastKnownTimestamp.Format(time.RFC3339))
280
}
281
282
var (
···
287
// handle now playing track separately
288
if len(tracks) > 0 && tracks[0].Attr != nil && tracks[0].Attr.NowPlaying == "true" {
289
nowPlayingTrack := tracks[0]
290
-
log.Printf("now playing track for %s: %s - %s", username, nowPlayingTrack.Artist.Text, nowPlayingTrack.Name)
291
l.mu.Lock()
292
lastSeen, existed := l.lastSeenNowPlaying[username]
293
// if our current track matches with last seen
294
// just compare artist/album/name for now
295
if existed && lastSeen.Album == nowPlayingTrack.Album && lastSeen.Name == nowPlayingTrack.Name && lastSeen.Artist == nowPlayingTrack.Artist {
296
-
log.Printf("current track matches last seen track for %s", username)
297
} else {
298
-
log.Printf("current track does not match last seen track for %s", username)
299
// aha! we record this!
300
l.lastSeenNowPlaying[username] = nowPlayingTrack
301
}
···
312
}
313
314
if lastNonNowPlaying == nil {
315
-
log.Printf("no non-now-playing tracks found for user %s.", username)
316
return nil
317
}
318
319
latestTrackTime := lastNonNowPlaying.Date
320
321
// print both
322
-
fmt.Printf("latestTrackTime: %s\n", latestTrackTime)
323
-
fmt.Printf("lastKnownTimestamp: %s\n", lastKnownTimestamp)
324
325
if lastKnownTimestamp != nil && lastKnownTimestamp.Equal(latestTrackTime.Time) {
326
-
log.Printf("no new tracks to process for user %s.", username)
327
return nil
328
}
329
330
for _, track := range tracks {
331
if track.Date == nil {
332
-
log.Printf("skipping track without timestamp for %s: %s - %s", username, track.Artist.Text, track.Name)
333
continue
334
}
335
···
337
// before or at last known
338
if lastKnownTimestamp != nil && (trackTime.Before(*lastKnownTimestamp) || trackTime.Equal(*lastKnownTimestamp)) {
339
if processedCount == 0 {
340
-
log.Printf("reached already known scrobbles for user %s (track time: %s, last known: %s).",
341
username, trackTime.Format(time.RFC3339), lastKnownTimestamp.Format(time.RFC3339))
342
}
343
break
···
360
361
hydratedTrack, err := musicbrainz.HydrateTrack(l.musicBrainzService, baseTrack)
362
if err != nil {
363
-
log.Printf("error hydrating track for user %s: %s - %s: %v", username, track.Artist.Text, track.Name, err)
364
// we can use the track without MBIDs, it's still valid
365
hydratedTrack = &baseTrack
366
}
367
l.db.SaveTrack(user.ID, hydratedTrack)
368
-
log.Printf("Submitting track")
369
err = l.SubmitTrackToPDS(*user.ATProtoDID, hydratedTrack, ctx)
370
if err != nil {
371
-
log.Printf("error submitting track for user %s: %s - %s: %v", username, track.Artist.Text, track.Name, err)
372
}
373
processedCount++
374
···
382
}
383
384
if processedCount > 0 {
385
-
log.Printf("processed %d new track(s) for user %s. latest timestamp: %s",
386
processedCount, username, latestProcessedTime.Format(time.RFC3339))
387
}
388
···
407
}
408
409
// printout the session details
410
-
fmt.Printf("Submitting track for the did: %+v\n", sess.DID)
411
412
artists := make([]*teal.AlphaFeedDefs_Artist, 0, len(track.Artist))
413
for _, a := range track.Artist {
···
9
"log"
10
"net/http"
11
"net/url"
12
+
"os"
13
"strconv"
14
"sync"
15
"time"
···
41
atprotoService *atprotoauth.ATprotoAuthService
42
lastSeenNowPlaying map[string]Track
43
mu sync.Mutex
44
+
logger *log.Logger
45
}
46
47
func NewLastFMService(db *db.DB, apiKey string, musicBrainzService *musicbrainz.MusicBrainzService, atprotoService *atprotoauth.ATprotoAuthService) *LastFMService {
48
+
logger := log.New(os.Stdout, "lastfm: ", log.LstdFlags|log.Lmsgprefix)
49
+
50
return &LastFMService{
51
db: db,
52
httpClient: &http.Client{
···
60
musicBrainzService: musicBrainzService,
61
lastSeenNowPlaying: make(map[string]Track),
62
mu: sync.Mutex{},
63
+
logger: logger,
64
}
65
}
66
67
func (l *LastFMService) loadUsernames() error {
68
u, err := l.db.GetAllUsersWithLastFM()
69
if err != nil {
70
+
l.logger.Printf("Error loading users with Last.fm from DB: %v", err)
71
return fmt.Errorf("failed to load users from database: %w", err)
72
}
73
usernames := make([]string, len(u))
···
76
if user.LastFMUsername != nil { // Check if the username is set
77
usernames[i] = *user.LastFMUsername
78
} else {
79
+
l.logger.Printf("User ID %d has Last.fm enabled but no username set", user.ID)
80
}
81
}
82
···
89
}
90
91
l.Usernames = filteredUsernames
92
+
l.logger.Printf("Loaded %d Last.fm usernames", len(l.Usernames))
93
94
return nil
95
}
···
118
return nil, fmt.Errorf("failed to create request for %s: %w", username, err)
119
}
120
121
+
l.logger.Printf("Fetching recent tracks for user: %s", username)
122
resp, err := l.httpClient.Do(req)
123
if err != nil {
124
return nil, fmt.Errorf("failed to fetch recent tracks for %s: %w", username, err)
···
139
}
140
if err := json.Unmarshal(bodyBytes, &recentTracksResp); err != nil {
141
// Log the body content that failed to decode
142
+
l.logger.Printf("Failed to decode response body for %s: %s", username, string(bodyBytes))
143
return nil, fmt.Errorf("failed to decode response for %s: %w", username, err)
144
}
145
146
if len(recentTracksResp.RecentTracks.Tracks) > 0 {
147
+
l.logger.Printf("Fetched %d tracks for %s. Most recent: %s - %s",
148
len(recentTracksResp.RecentTracks.Tracks),
149
username,
150
recentTracksResp.RecentTracks.Tracks[0].Artist.Text,
151
recentTracksResp.RecentTracks.Tracks[0].Name)
152
} else {
153
+
l.logger.Printf("No recent tracks found for %s", username)
154
}
155
156
return &recentTracksResp, nil
···
158
159
func (l *LastFMService) StartListeningTracker(interval time.Duration) {
160
if err := l.loadUsernames(); err != nil {
161
+
l.logger.Printf("Failed to perform initial username load: %v", err)
162
// Decide if we should proceed without initial load or return error
163
}
164
165
if len(l.Usernames) == 0 {
166
+
l.logger.Println("No Last.fm users configured. Tracker will run but fetch cycles will be skipped until users are added.")
167
} else {
168
+
l.logger.Printf("Found %d Last.fm users.", len(l.Usernames))
169
}
170
171
ticker := time.NewTicker(interval)
···
174
if len(l.Usernames) > 0 {
175
l.fetchAllUserTracks(context.Background())
176
} else {
177
+
l.logger.Println("Skipping initial fetch cycle as no users are configured.")
178
}
179
180
for {
···
182
case <-ticker.C:
183
// refresh usernames periodically from db
184
if err := l.loadUsernames(); err != nil {
185
+
l.logger.Printf("Error reloading usernames in ticker: %v", err)
186
// Continue ticker loop even if reload fails? Or log and potentially stop?
187
continue // Continue for now
188
}
189
if len(l.Usernames) > 0 {
190
l.fetchAllUserTracks(context.Background())
191
} else {
192
+
l.logger.Println("No Last.fm users configured. Skipping fetch cycle.")
193
}
194
// TODO: Implement graceful shutdown using context cancellation
195
// case <-ctx.Done():
196
+
// l.logger.Println("Stopping Last.fm listening tracker.")
197
// ticker.Stop()
198
// return
199
}
200
}
201
}()
202
203
+
l.logger.Printf("Last.fm Listening Tracker started with interval %v", interval)
204
}
205
206
// fetchAllUserTracks iterates through users and fetches their tracks.
207
func (l *LastFMService) fetchAllUserTracks(ctx context.Context) {
208
+
l.logger.Printf("Starting fetch cycle for %d users...", len(l.Usernames))
209
var wg sync.WaitGroup // Use WaitGroup to fetch concurrently (optional)
210
fetchErrors := make(chan error, len(l.Usernames)) // Channel for errors
211
212
for _, username := range l.Usernames {
213
if ctx.Err() != nil {
214
+
l.logger.Printf("Context cancelled before starting fetch for user %s.", username)
215
break // Exit loop if context is cancelled
216
}
217
···
219
go func(uname string) { // Launch fetch and process in a goroutine per user
220
defer wg.Done()
221
if ctx.Err() != nil {
222
+
l.logger.Printf("Context cancelled during fetch cycle for user %s.", uname)
223
return // Exit goroutine if context is cancelled
224
}
225
···
228
const fetchLimit = 5
229
recentTracks, err := l.getRecentTracks(ctx, uname, fetchLimit)
230
if err != nil {
231
+
l.logger.Printf("Error fetching tracks for %s: %v", uname, err)
232
fetchErrors <- fmt.Errorf("fetch failed for %s: %w", uname, err) // Report error
233
return
234
}
235
236
if recentTracks == nil || len(recentTracks.RecentTracks.Tracks) == 0 {
237
+
l.logger.Printf("No tracks returned for user %s", uname)
238
return
239
}
240
241
// Process the fetched tracks
242
if err := l.processTracks(ctx, uname, recentTracks.RecentTracks.Tracks); err != nil {
243
+
l.logger.Printf("Error processing tracks for %s: %v", uname, err)
244
fetchErrors <- fmt.Errorf("process failed for %s: %w", uname, err) // Report error
245
}
246
}(username)
···
252
// Log any errors that occurred during the fetch cycle
253
errorCount := 0
254
for err := range fetchErrors {
255
+
l.logger.Printf("Fetch cycle error: %v", err)
256
errorCount++
257
}
258
259
if errorCount > 0 {
260
+
l.logger.Printf("Finished fetch cycle with %d errors.", errorCount)
261
} else {
262
+
l.logger.Println("Finished fetch cycle successfully.")
263
}
264
}
265
···
279
}
280
281
if lastKnownTimestamp == nil {
282
+
l.logger.Printf("no previous scrobble timestamp found for user %s. processing latest track.", username)
283
} else {
284
+
l.logger.Printf("last known scrobble for %s was at %s", username, lastKnownTimestamp.Format(time.RFC3339))
285
}
286
287
var (
···
292
// handle now playing track separately
293
if len(tracks) > 0 && tracks[0].Attr != nil && tracks[0].Attr.NowPlaying == "true" {
294
nowPlayingTrack := tracks[0]
295
+
l.logger.Printf("now playing track for %s: %s - %s", username, nowPlayingTrack.Artist.Text, nowPlayingTrack.Name)
296
l.mu.Lock()
297
lastSeen, existed := l.lastSeenNowPlaying[username]
298
// if our current track matches with last seen
299
// just compare artist/album/name for now
300
if existed && lastSeen.Album == nowPlayingTrack.Album && lastSeen.Name == nowPlayingTrack.Name && lastSeen.Artist == nowPlayingTrack.Artist {
301
+
l.logger.Printf("current track matches last seen track for %s", username)
302
} else {
303
+
l.logger.Printf("current track does not match last seen track for %s", username)
304
// aha! we record this!
305
l.lastSeenNowPlaying[username] = nowPlayingTrack
306
}
···
317
}
318
319
if lastNonNowPlaying == nil {
320
+
l.logger.Printf("no non-now-playing tracks found for user %s.", username)
321
return nil
322
}
323
324
latestTrackTime := lastNonNowPlaying.Date
325
326
// print both
327
+
l.logger.Printf("latestTrackTime: %s\n", latestTrackTime)
328
+
l.logger.Printf("lastKnownTimestamp: %s\n", lastKnownTimestamp)
329
330
if lastKnownTimestamp != nil && lastKnownTimestamp.Equal(latestTrackTime.Time) {
331
+
l.logger.Printf("no new tracks to process for user %s.", username)
332
return nil
333
}
334
335
for _, track := range tracks {
336
if track.Date == nil {
337
+
l.logger.Printf("skipping track without timestamp for %s: %s - %s", username, track.Artist.Text, track.Name)
338
continue
339
}
340
···
342
// before or at last known
343
if lastKnownTimestamp != nil && (trackTime.Before(*lastKnownTimestamp) || trackTime.Equal(*lastKnownTimestamp)) {
344
if processedCount == 0 {
345
+
l.logger.Printf("reached already known scrobbles for user %s (track time: %s, last known: %s).",
346
username, trackTime.Format(time.RFC3339), lastKnownTimestamp.Format(time.RFC3339))
347
}
348
break
···
365
366
hydratedTrack, err := musicbrainz.HydrateTrack(l.musicBrainzService, baseTrack)
367
if err != nil {
368
+
l.logger.Printf("error hydrating track for user %s: %s - %s: %v", username, track.Artist.Text, track.Name, err)
369
// we can use the track without MBIDs, it's still valid
370
hydratedTrack = &baseTrack
371
}
372
l.db.SaveTrack(user.ID, hydratedTrack)
373
+
l.logger.Printf("Submitting track")
374
err = l.SubmitTrackToPDS(*user.ATProtoDID, hydratedTrack, ctx)
375
if err != nil {
376
+
l.logger.Printf("error submitting track for user %s: %s - %s: %v", username, track.Artist.Text, track.Name, err)
377
}
378
processedCount++
379
···
387
}
388
389
if processedCount > 0 {
390
+
l.logger.Printf("processed %d new track(s) for user %s. latest timestamp: %s",
391
processedCount, username, latestProcessedTime.Format(time.RFC3339))
392
}
393
···
412
}
413
414
// printout the session details
415
+
l.logger.Printf("Submitting track for the did: %+v\n", sess.DID)
416
417
artists := make([]*teal.AlphaFeedDefs_Artist, 0, len(track.Artist))
418
for _, a := range track.Artist {
+11
-8
service/musicbrainz/musicbrainz.go
+11
-8
service/musicbrainz/musicbrainz.go
···
8
"log"
9
"net/http"
10
"net/url"
11
"sort"
12
"strings"
13
"sync" // Added for mutex
···
75
cacheMutex sync.RWMutex // Mutex to protect the cache
76
cacheTTL time.Duration // Time-to-live for cache entries
77
cleaner MetadataCleaner // Cleaner for cleaning up expired cache entries
78
}
79
80
// NewMusicBrainzService creates a new service instance with rate limiting and caching.
···
83
limiter := rate.NewLimiter(rate.Every(time.Second), 1)
84
// Set a default cache TTL (e.g., 1 hour)
85
defaultCacheTTL := 1 * time.Hour
86
-
87
return &MusicBrainzService{
88
db: db,
89
httpClient: &http.Client{
···
94
cacheTTL: defaultCacheTTL, // Set the cache TTL
95
cleaner: *NewMetadataCleaner("Latin"), // Initialize the cleaner
96
// cacheMutex is zero-value ready
97
}
98
}
99
···
127
s.cacheMutex.RUnlock()
128
129
if found && now.Before(entry.expiresAt) {
130
-
log.Printf("Cache hit for MusicBrainz search: key=%s", cacheKey)
131
// Return the cached data directly. Consider if a deep copy is needed if callers modify results.
132
return entry.recordings, nil
133
}
134
// --- Cache Miss or Expired ---
135
if found {
136
-
log.Printf("Cache expired for MusicBrainz search: key=%s", cacheKey)
137
} else {
138
-
log.Printf("Cache miss for MusicBrainz search: key=%s", cacheKey)
139
}
140
141
// --- Proceed with API call ---
···
191
expiresAt: time.Now().UTC().Add(s.cacheTTL),
192
}
193
s.cacheMutex.Unlock()
194
-
log.Printf("Cached MusicBrainz search result for key=%s, TTL=%s", cacheKey, s.cacheTTL)
195
196
// Return the newly fetched results
197
return result.Recordings, nil
198
}
199
200
// GetBestRelease selects the 'best' release from a list based on specific criteria.
201
-
func GetBestRelease(releases []MusicBrainzRelease, trackTitle string) *MusicBrainzRelease {
202
if len(releases) == 0 {
203
return nil
204
}
···
251
}
252
253
// 3. If none found, return the oldest release overall (which is the first one after sorting)
254
-
log.Printf("Could not find a suitable release for '%s', picking oldest: '%s' (%s)", trackTitle, releases[0].Title, releases[0].ID)
255
r := releases[0]
256
return &r
257
}
···
279
}
280
281
firstResult := res[0]
282
-
firstResultAlbum := GetBestRelease(firstResult.Releases, firstResult.Title)
283
284
// woof. we Might not have any ISRCs!
285
var bestISRC string
···
8
"log"
9
"net/http"
10
"net/url"
11
+
"os"
12
"sort"
13
"strings"
14
"sync" // Added for mutex
···
76
cacheMutex sync.RWMutex // Mutex to protect the cache
77
cacheTTL time.Duration // Time-to-live for cache entries
78
cleaner MetadataCleaner // Cleaner for cleaning up expired cache entries
79
+
logger *log.Logger // Logger for logging
80
}
81
82
// NewMusicBrainzService creates a new service instance with rate limiting and caching.
···
85
limiter := rate.NewLimiter(rate.Every(time.Second), 1)
86
// Set a default cache TTL (e.g., 1 hour)
87
defaultCacheTTL := 1 * time.Hour
88
+
logger := log.New(os.Stdout, "musicbrainz: ", log.LstdFlags|log.Lmsgprefix)
89
return &MusicBrainzService{
90
db: db,
91
httpClient: &http.Client{
···
96
cacheTTL: defaultCacheTTL, // Set the cache TTL
97
cleaner: *NewMetadataCleaner("Latin"), // Initialize the cleaner
98
// cacheMutex is zero-value ready
99
+
logger: logger,
100
}
101
}
102
···
130
s.cacheMutex.RUnlock()
131
132
if found && now.Before(entry.expiresAt) {
133
+
s.logger.Printf("Cache hit for MusicBrainz search: key=%s", cacheKey)
134
// Return the cached data directly. Consider if a deep copy is needed if callers modify results.
135
return entry.recordings, nil
136
}
137
// --- Cache Miss or Expired ---
138
if found {
139
+
s.logger.Printf("Cache expired for MusicBrainz search: key=%s", cacheKey)
140
} else {
141
+
s.logger.Printf("Cache miss for MusicBrainz search: key=%s", cacheKey)
142
}
143
144
// --- Proceed with API call ---
···
194
expiresAt: time.Now().UTC().Add(s.cacheTTL),
195
}
196
s.cacheMutex.Unlock()
197
+
s.logger.Printf("Cached MusicBrainz search result for key=%s, TTL=%s", cacheKey, s.cacheTTL)
198
199
// Return the newly fetched results
200
return result.Recordings, nil
201
}
202
203
// GetBestRelease selects the 'best' release from a list based on specific criteria.
204
+
func (s *MusicBrainzService) GetBestRelease(releases []MusicBrainzRelease, trackTitle string) *MusicBrainzRelease {
205
if len(releases) == 0 {
206
return nil
207
}
···
254
}
255
256
// 3. If none found, return the oldest release overall (which is the first one after sorting)
257
+
s.logger.Printf("Could not find a suitable release for '%s', picking oldest: '%s' (%s)", trackTitle, releases[0].Title, releases[0].ID)
258
r := releases[0]
259
return &r
260
}
···
282
}
283
284
firstResult := res[0]
285
+
firstResultAlbum := mb.GetBestRelease(firstResult.Releases, firstResult.Title)
286
287
// woof. we Might not have any ISRCs!
288
var bestISRC string
+47
-42
service/spotify/spotify.go
+47
-42
service/spotify/spotify.go
···
9
"log"
10
"net/http"
11
"net/url"
12
"strings"
13
"sync"
14
"time"
···
34
userTracks map[int64]*models.Track
35
userTokens map[int64]string
36
mu sync.RWMutex
37
}
38
39
func NewSpotifyService(database *db.DB, atprotoService *atprotoauth.ATprotoAuthService, musicBrainzService *musicbrainz.MusicBrainzService) *SpotifyService {
40
return &SpotifyService{
41
DB: database,
42
atprotoService: atprotoService,
43
mb: musicBrainzService,
44
userTracks: make(map[int64]*models.Track),
45
userTokens: make(map[int64]string),
46
}
47
}
48
49
func (s *SpotifyService) SubmitTrackToPDS(did string, track *models.Track, ctx context.Context) error {
50
client, err := s.atprotoService.GetATProtoClient()
51
if err != nil || client == nil {
52
-
log.Printf("Error getting ATProto client: %v", err)
53
return fmt.Errorf("failed to get ATProto client: %w", err)
54
}
55
···
110
111
var out atproto.RepoCreateRecord_Output
112
if err := xrpcClient.Do(ctx, authArgs, xrpc.Procedure, "application/json", "com.atproto.repo.createRecord", nil, input, &out); err != nil {
113
-
log.Printf("Error creating record for DID %s: %v. Input: %+v", did, err, input)
114
return fmt.Errorf("failed to create record on PDS for DID %s: %w", did, err)
115
}
116
117
-
log.Printf("Successfully submitted track '%s' to PDS for DID %s. Record URI: %s", track.Name, did, out.Uri)
118
return nil
119
}
120
121
func (s *SpotifyService) SetAccessToken(token string, refreshToken string, userId int64, hasSession bool) (int64, error) {
122
userID, err := s.identifyAndStoreUser(token, refreshToken, userId, hasSession)
123
if err != nil {
124
-
log.Printf("Error identifying and storing user: %v", err)
125
return 0, err
126
}
127
return userID, nil
···
130
func (s *SpotifyService) identifyAndStoreUser(token string, refreshToken string, userId int64, hasSession bool) (int64, error) {
131
userProfile, err := s.fetchSpotifyProfile(token)
132
if err != nil {
133
-
log.Printf("Error fetching Spotify profile: %v", err)
134
return 0, err
135
}
136
137
-
fmt.Printf("uid: %d hasSession: %t", userId, hasSession)
138
139
user, err := s.DB.GetUserBySpotifyID(userProfile.ID)
140
if err != nil {
141
// This error might mean DB connection issue, not just user not found.
142
-
log.Printf("Error checking for user by Spotify ID %s: %v", userProfile.ID, err)
143
return 0, err
144
}
145
···
148
// We don't intend users to log in via spotify!
149
if user == nil {
150
if !hasSession {
151
-
log.Printf("User does not seem to exist")
152
return 0, fmt.Errorf("user does not seem to exist")
153
} else {
154
// overwrite prev user
155
user, err = s.DB.AddSpotifySession(userId, userProfile.DisplayName, userProfile.Email, userProfile.ID, token, refreshToken, tokenExpiryTime)
156
if err != nil {
157
-
log.Printf("Error adding Spotify session for user ID %d: %v", userId, err)
158
return 0, err
159
}
160
}
···
162
err = s.DB.UpdateUserToken(user.ID, token, refreshToken, tokenExpiryTime)
163
if err != nil {
164
// for now log and continue
165
-
log.Printf("Error updating user token for user ID %d: %v", user.ID, err)
166
} else {
167
-
log.Printf("Updated token for existing user: %s (ID: %d)", *user.Username, user.ID)
168
}
169
}
170
user.AccessToken = &token
···
174
s.userTokens[user.ID] = token
175
s.mu.Unlock()
176
177
-
log.Printf("User authenticated via Spotify: %s (ID: %d)", *user.Username, user.ID)
178
return user.ID, nil
179
}
180
···
203
token, err := s.refreshTokenInner(user.ID)
204
if err != nil {
205
//Probably should remove the access token and refresh in long run?
206
-
log.Printf("Error refreshing token for user %d: %v", user.ID, err)
207
continue
208
}
209
s.userTokens[user.ID] = token
210
}
211
}
212
213
-
log.Printf("Loaded %d active users with valid tokens", count)
214
return nil
215
}
216
···
280
// Also clear the bad refresh token from the DB
281
updateErr := s.DB.UpdateUserToken(userID, "", "", time.Now().UTC()) // Clear tokens
282
if updateErr != nil {
283
-
log.Printf("Failed to clear bad refresh token for user %d: %v", userID, updateErr)
284
}
285
return "", fmt.Errorf("spotify token refresh failed (%d): %s", resp.StatusCode, string(body))
286
}
···
306
// Update DB
307
if err := s.DB.UpdateUserToken(userID, tokenResponse.AccessToken, newRefreshToken, newExpiry); err != nil {
308
// Log error but continue, as we have the token in memory
309
-
log.Printf("Error updating user token in DB for user %d after refresh: %v", userID, err)
310
}
311
312
// Update in-memory cache
···
314
s.userTokens[userID] = tokenResponse.AccessToken
315
s.mu.Unlock()
316
317
-
log.Printf("Successfully refreshed token for user %d", userID)
318
return tokenResponse.AccessToken, nil
319
}
320
···
329
func (s *SpotifyService) RefreshExpiredTokens() {
330
users, err := s.DB.GetUsersWithExpiredTokens()
331
if err != nil {
332
-
log.Printf("Error fetching users with expired tokens: %v", err)
333
return
334
}
335
···
344
345
if err != nil {
346
// just print out errors here for now
347
-
log.Printf("Error from service/spotify/spotify.go when refreshing tokens: %s", err.Error())
348
}
349
350
refreshed++
351
}
352
353
if refreshed > 0 {
354
-
log.Printf("Refreshed tokens for %d users", refreshed)
355
}
356
}
357
···
412
tracks, err := s.DB.GetRecentTracks(userID, 20)
413
if err != nil {
414
http.Error(w, "Error retrieving track history", http.StatusInternalServerError)
415
-
log.Printf("Error retrieving track history: %v", err)
416
return
417
}
418
···
454
455
// oops, token expired or other client error
456
if resp.StatusCode == 401 && attempt == 0 { // Only refresh on 401 on the first attempt
457
-
log.Printf("Spotify token potentially expired for user %d, attempting refresh...", userID)
458
newAccessToken, refreshErr := s.refreshTokenInner(userID)
459
if refreshErr != nil {
460
-
log.Printf("Token refresh failed for user %d: %v", userID, refreshErr)
461
// No point retrying if refresh failed
462
return nil, fmt.Errorf("spotify token expired or invalid for user %d and refresh failed: %w", userID, refreshErr)
463
}
464
-
log.Printf("Token refreshed for user %d, retrying request...", userID)
465
token = newAccessToken // Update token for the next attempt
466
req.Header.Set("Authorization", "Bearer "+token) // Update header for retry
467
continue // Go to next attempt in the loop
···
555
for range ticker.C {
556
err := s.LoadAllUsers()
557
if err != nil {
558
-
log.Printf("Error loading spotify users: %v", err)
559
continue
560
}
561
// copy userIDs to avoid holding the lock too long
···
569
for _, userID := range userIDs {
570
track, err := s.FetchCurrentTrack(userID)
571
if err != nil {
572
-
log.Printf("Error fetching track for user %d: %v", userID, err)
573
continue
574
}
575
···
603
604
// just log when we stamp tracks
605
if isNewTrack && isLastTrackStamped && !currentTrack.HasStamped {
606
-
log.Printf("User %d stamped (previous) track: %s by %s", userID, currentTrack.Name, currentTrack.Artist)
607
currentTrack.HasStamped = true
608
if currentTrack.PlayID != 0 {
609
s.DB.UpdateTrack(currentTrack.PlayID, currentTrack)
610
611
-
log.Printf("Updated!")
612
}
613
}
614
615
if isStamped && !currentTrack.HasStamped {
616
-
log.Printf("User %d stamped track: %s by %s", userID, track.Name, track.Artist)
617
track.HasStamped = true
618
// if currenttrack has a playid and the last track is the same as the current track
619
if !isNewTrack && currentTrack.PlayID != 0 {
···
624
s.userTracks[userID] = track
625
s.mu.Unlock()
626
627
-
log.Printf("Updated!")
628
}
629
}
630
631
if isNewTrack {
632
id, err := s.DB.SaveTrack(userID, track)
633
if err != nil {
634
-
log.Printf("Error saving track for user %d: %v", userID, err)
635
continue
636
}
637
···
645
// The 'track' variable is *models.Track and has been saved to DB, PlayID is populated.
646
dbUser, errUser := s.DB.GetUserByID(userID) // Fetch user by their internal ID
647
if errUser != nil {
648
-
log.Printf("User %d: Error fetching user details for PDS submission: %v", userID, errUser)
649
} else if dbUser == nil {
650
-
log.Printf("User %d: User not found in DB. Skipping PDS submission.", userID)
651
} else if dbUser.ATProtoDID == nil || *dbUser.ATProtoDID == "" {
652
-
log.Printf("User %d (%d): ATProto DID not set. Skipping PDS submission for track '%s'.", userID, dbUser.ATProtoDID, track.Name)
653
} else {
654
// User has a DID, proceed with hydration and submission
655
var trackToSubmitToPDS *models.Track = track // Default to the original track (already *models.Track)
···
658
// and it returns *models.Track
659
hydratedTrack, errHydrate := musicbrainz.HydrateTrack(s.mb, *track)
660
if errHydrate != nil {
661
-
log.Printf("User %d (%d): Error hydrating track '%s' with MusicBrainz: %v. Proceeding with original track data for PDS.", userID, dbUser.ATProtoDID, track.Name, errHydrate)
662
} else {
663
-
log.Printf("User %d (%d): Successfully hydrated track '%s' with MusicBrainz.", userID, dbUser.ATProtoDID, track.Name)
664
trackToSubmitToPDS = hydratedTrack // hydratedTrack is *models.Track
665
}
666
} else {
667
-
log.Printf("User %d (%d): MusicBrainz service not configured. Proceeding with original track data for PDS.", userID, dbUser.ATProtoDID)
668
}
669
670
artistName := "Unknown Artist"
···
672
artistName = trackToSubmitToPDS.Artist[0].Name
673
}
674
675
-
log.Printf("User %d (%d): Attempting to submit track '%s' by %s to PDS (DID: %s)", userID, dbUser.ATProtoDID, trackToSubmitToPDS.Name, artistName, *dbUser.ATProtoDID)
676
// Use context.Background() for now, or pass down a context if available
677
if errPDS := s.SubmitTrackToPDS(*dbUser.ATProtoDID, trackToSubmitToPDS, context.Background()); errPDS != nil {
678
-
log.Printf("User %d (%d): Error submitting track '%s' to PDS: %v", userID, dbUser.ATProtoDID, trackToSubmitToPDS.Name, errPDS)
679
} else {
680
-
log.Printf("User %d (%d): Successfully submitted track '%s' to PDS.", userID, dbUser.ATProtoDID, trackToSubmitToPDS.Name)
681
}
682
}
683
// End of PDS submission block
684
685
-
log.Printf("User %d is listening to: %s by %s", userID, track.Name, track.Artist)
686
}
687
}
688
689
//unloading users to save memory and make sure we get new signups
690
err = s.LoadAllUsers()
691
if err != nil {
692
-
log.Printf("Error loading spotify users: %v", err)
693
}
694
}
695
}
···
9
"log"
10
"net/http"
11
"net/url"
12
+
"os"
13
"strings"
14
"sync"
15
"time"
···
35
userTracks map[int64]*models.Track
36
userTokens map[int64]string
37
mu sync.RWMutex
38
+
logger *log.Logger
39
}
40
41
func NewSpotifyService(database *db.DB, atprotoService *atprotoauth.ATprotoAuthService, musicBrainzService *musicbrainz.MusicBrainzService) *SpotifyService {
42
+
logger := log.New(os.Stdout, "spotify: ", log.LstdFlags|log.Lmsgprefix)
43
+
44
return &SpotifyService{
45
DB: database,
46
atprotoService: atprotoService,
47
mb: musicBrainzService,
48
userTracks: make(map[int64]*models.Track),
49
userTokens: make(map[int64]string),
50
+
logger: logger,
51
}
52
}
53
54
func (s *SpotifyService) SubmitTrackToPDS(did string, track *models.Track, ctx context.Context) error {
55
client, err := s.atprotoService.GetATProtoClient()
56
if err != nil || client == nil {
57
+
s.logger.Printf("Error getting ATProto client: %v", err)
58
return fmt.Errorf("failed to get ATProto client: %w", err)
59
}
60
···
115
116
var out atproto.RepoCreateRecord_Output
117
if err := xrpcClient.Do(ctx, authArgs, xrpc.Procedure, "application/json", "com.atproto.repo.createRecord", nil, input, &out); err != nil {
118
+
s.logger.Printf("Error creating record for DID %s: %v. Input: %+v", did, err, input)
119
return fmt.Errorf("failed to create record on PDS for DID %s: %w", did, err)
120
}
121
122
+
s.logger.Printf("Successfully submitted track '%s' to PDS for DID %s. Record URI: %s", track.Name, did, out.Uri)
123
return nil
124
}
125
126
func (s *SpotifyService) SetAccessToken(token string, refreshToken string, userId int64, hasSession bool) (int64, error) {
127
userID, err := s.identifyAndStoreUser(token, refreshToken, userId, hasSession)
128
if err != nil {
129
+
s.logger.Printf("Error identifying and storing user: %v", err)
130
return 0, err
131
}
132
return userID, nil
···
135
func (s *SpotifyService) identifyAndStoreUser(token string, refreshToken string, userId int64, hasSession bool) (int64, error) {
136
userProfile, err := s.fetchSpotifyProfile(token)
137
if err != nil {
138
+
s.logger.Printf("Error fetching Spotify profile: %v", err)
139
return 0, err
140
}
141
142
+
s.logger.Printf("uid: %d hasSession: %t", userId, hasSession)
143
144
user, err := s.DB.GetUserBySpotifyID(userProfile.ID)
145
if err != nil {
146
// This error might mean DB connection issue, not just user not found.
147
+
s.logger.Printf("Error checking for user by Spotify ID %s: %v", userProfile.ID, err)
148
return 0, err
149
}
150
···
153
// We don't intend users to log in via spotify!
154
if user == nil {
155
if !hasSession {
156
+
s.logger.Printf("User does not seem to exist")
157
return 0, fmt.Errorf("user does not seem to exist")
158
} else {
159
// overwrite prev user
160
user, err = s.DB.AddSpotifySession(userId, userProfile.DisplayName, userProfile.Email, userProfile.ID, token, refreshToken, tokenExpiryTime)
161
if err != nil {
162
+
s.logger.Printf("Error adding Spotify session for user ID %d: %v", userId, err)
163
return 0, err
164
}
165
}
···
167
err = s.DB.UpdateUserToken(user.ID, token, refreshToken, tokenExpiryTime)
168
if err != nil {
169
// for now log and continue
170
+
s.logger.Printf("Error updating user token for user ID %d: %v", user.ID, err)
171
} else {
172
+
s.logger.Printf("Updated token for existing user: %s (ID: %d)", *user.Username, user.ID)
173
}
174
}
175
user.AccessToken = &token
···
179
s.userTokens[user.ID] = token
180
s.mu.Unlock()
181
182
+
s.logger.Printf("User authenticated via Spotify: %s (ID: %d)", *user.Username, user.ID)
183
return user.ID, nil
184
}
185
···
208
token, err := s.refreshTokenInner(user.ID)
209
if err != nil {
210
//Probably should remove the access token and refresh in long run?
211
+
s.logger.Printf("Error refreshing token for user %d: %v", user.ID, err)
212
continue
213
}
214
s.userTokens[user.ID] = token
215
}
216
}
217
218
+
s.logger.Printf("Loaded %d active users with valid tokens", count)
219
return nil
220
}
221
···
285
// Also clear the bad refresh token from the DB
286
updateErr := s.DB.UpdateUserToken(userID, "", "", time.Now().UTC()) // Clear tokens
287
if updateErr != nil {
288
+
s.logger.Printf("Failed to clear bad refresh token for user %d: %v", userID, updateErr)
289
}
290
return "", fmt.Errorf("spotify token refresh failed (%d): %s", resp.StatusCode, string(body))
291
}
···
311
// Update DB
312
if err := s.DB.UpdateUserToken(userID, tokenResponse.AccessToken, newRefreshToken, newExpiry); err != nil {
313
// Log error but continue, as we have the token in memory
314
+
s.logger.Printf("Error updating user token in DB for user %d after refresh: %v", userID, err)
315
}
316
317
// Update in-memory cache
···
319
s.userTokens[userID] = tokenResponse.AccessToken
320
s.mu.Unlock()
321
322
+
s.logger.Printf("Successfully refreshed token for user %d", userID)
323
return tokenResponse.AccessToken, nil
324
}
325
···
334
func (s *SpotifyService) RefreshExpiredTokens() {
335
users, err := s.DB.GetUsersWithExpiredTokens()
336
if err != nil {
337
+
s.logger.Printf("Error fetching users with expired tokens: %v", err)
338
return
339
}
340
···
349
350
if err != nil {
351
// just print out errors here for now
352
+
s.logger.Printf("Error from service/spotify/spotify.go when refreshing tokens: %s", err.Error())
353
}
354
355
refreshed++
356
}
357
358
if refreshed > 0 {
359
+
s.logger.Printf("Refreshed tokens for %d users", refreshed)
360
}
361
}
362
···
417
tracks, err := s.DB.GetRecentTracks(userID, 20)
418
if err != nil {
419
http.Error(w, "Error retrieving track history", http.StatusInternalServerError)
420
+
s.logger.Printf("Error retrieving track history: %v", err)
421
return
422
}
423
···
459
460
// oops, token expired or other client error
461
if resp.StatusCode == 401 && attempt == 0 { // Only refresh on 401 on the first attempt
462
+
s.logger.Printf("Spotify token potentially expired for user %d, attempting refresh...", userID)
463
newAccessToken, refreshErr := s.refreshTokenInner(userID)
464
if refreshErr != nil {
465
+
s.logger.Printf("Token refresh failed for user %d: %v", userID, refreshErr)
466
// No point retrying if refresh failed
467
return nil, fmt.Errorf("spotify token expired or invalid for user %d and refresh failed: %w", userID, refreshErr)
468
}
469
+
s.logger.Printf("Token refreshed for user %d, retrying request...", userID)
470
token = newAccessToken // Update token for the next attempt
471
req.Header.Set("Authorization", "Bearer "+token) // Update header for retry
472
continue // Go to next attempt in the loop
···
560
for range ticker.C {
561
err := s.LoadAllUsers()
562
if err != nil {
563
+
s.logger.Printf("Error loading spotify users: %v", err)
564
continue
565
}
566
// copy userIDs to avoid holding the lock too long
···
574
for _, userID := range userIDs {
575
track, err := s.FetchCurrentTrack(userID)
576
if err != nil {
577
+
s.logger.Printf("Error fetching track for user %d: %v", userID, err)
578
continue
579
}
580
···
608
609
// just log when we stamp tracks
610
if isNewTrack && isLastTrackStamped && !currentTrack.HasStamped {
611
+
s.logger.Printf("User %d stamped (previous) track: %s by %s", userID, currentTrack.Name, currentTrack.Artist)
612
currentTrack.HasStamped = true
613
if currentTrack.PlayID != 0 {
614
s.DB.UpdateTrack(currentTrack.PlayID, currentTrack)
615
616
+
s.logger.Printf("Updated!")
617
}
618
}
619
620
if isStamped && !currentTrack.HasStamped {
621
+
s.logger.Printf("User %d stamped track: %s by %s", userID, track.Name, track.Artist)
622
track.HasStamped = true
623
// if currenttrack has a playid and the last track is the same as the current track
624
if !isNewTrack && currentTrack.PlayID != 0 {
···
629
s.userTracks[userID] = track
630
s.mu.Unlock()
631
632
+
s.logger.Printf("Updated!")
633
}
634
}
635
636
if isNewTrack {
637
id, err := s.DB.SaveTrack(userID, track)
638
if err != nil {
639
+
s.logger.Printf("Error saving track for user %d: %v", userID, err)
640
continue
641
}
642
···
650
// The 'track' variable is *models.Track and has been saved to DB, PlayID is populated.
651
dbUser, errUser := s.DB.GetUserByID(userID) // Fetch user by their internal ID
652
if errUser != nil {
653
+
s.logger.Printf("User %d: Error fetching user details for PDS submission: %v", userID, errUser)
654
} else if dbUser == nil {
655
+
s.logger.Printf("User %d: User not found in DB. Skipping PDS submission.", userID)
656
} else if dbUser.ATProtoDID == nil || *dbUser.ATProtoDID == "" {
657
+
s.logger.Printf("User %d (%d): ATProto DID not set. Skipping PDS submission for track '%s'.", userID, dbUser.ATProtoDID, track.Name)
658
} else {
659
// User has a DID, proceed with hydration and submission
660
var trackToSubmitToPDS *models.Track = track // Default to the original track (already *models.Track)
···
663
// and it returns *models.Track
664
hydratedTrack, errHydrate := musicbrainz.HydrateTrack(s.mb, *track)
665
if errHydrate != nil {
666
+
s.logger.Printf("User %d (%d): Error hydrating track '%s' with MusicBrainz: %v. Proceeding with original track data for PDS.", userID, dbUser.ATProtoDID, track.Name, errHydrate)
667
} else {
668
+
s.logger.Printf("User %d (%d): Successfully hydrated track '%s' with MusicBrainz.", userID, dbUser.ATProtoDID, track.Name)
669
trackToSubmitToPDS = hydratedTrack // hydratedTrack is *models.Track
670
}
671
} else {
672
+
s.logger.Printf("User %d (%d): MusicBrainz service not configured. Proceeding with original track data for PDS.", userID, dbUser.ATProtoDID)
673
}
674
675
artistName := "Unknown Artist"
···
677
artistName = trackToSubmitToPDS.Artist[0].Name
678
}
679
680
+
s.logger.Printf("User %d (%d): Attempting to submit track '%s' by %s to PDS (DID: %s)", userID, dbUser.ATProtoDID, trackToSubmitToPDS.Name, artistName, *dbUser.ATProtoDID)
681
// Use context.Background() for now, or pass down a context if available
682
if errPDS := s.SubmitTrackToPDS(*dbUser.ATProtoDID, trackToSubmitToPDS, context.Background()); errPDS != nil {
683
+
s.logger.Printf("User %d (%d): Error submitting track '%s' to PDS: %v", userID, dbUser.ATProtoDID, trackToSubmitToPDS.Name, errPDS)
684
} else {
685
+
s.logger.Printf("User %d (%d): Successfully submitted track '%s' to PDS.", userID, dbUser.ATProtoDID, trackToSubmitToPDS.Name)
686
}
687
}
688
// End of PDS submission block
689
690
+
s.logger.Printf("User %d is listening to: %s by %s", userID, track.Name, track.Artist)
691
}
692
}
693
694
//unloading users to save memory and make sure we get new signups
695
err = s.LoadAllUsers()
696
if err != nil {
697
+
s.logger.Printf("Error loading spotify users: %v", err)
698
}
699
}
700
}