Warning: mysqli_real_connect(): Headers and client library minor version mismatch. Headers:50625 Library:50543 in /sites/rockbox.org/flyspray/adodb/drivers/adodb-mysqli.inc.php on line 108 FS#6639 : Last.fm logging broken on HWCODEC targets



FS#6639 - Last.fm logging broken on HWCODEC targets

Attached to Project: Rockbox
Opened by Robert Keevil (obo) - Friday, 09 February 2007, 19:07 GMT
Last edited by Robert Keevil (obo) - Thursday, 23 August 2007, 18:53 GMT
Task Type Patches
Category Music playback
Status Closed
Assigned To No-one
Operating System HW-codec
Severity Low
Priority Normal
Reported Version Daily build (which?)
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No


Last.fm logging appears to be broken on Archos targets.
scrobbler_init is initialising, but the audio_track_changed_event doesn't seem to be calling scrobbler_change_event. This is working fine on SWCODEC platforms.

The 2 attached patches help to show what is going on - one adds a debug menu screen, the other writes to a log file on every call to scrobbler_change_event. On HWCODEC targets no entries are logged to this file.
This task depends upon

Closed by  Robert Keevil (obo)
Thursday, 23 August 2007, 18:53 GMT
Reason for closing:  Accepted
Additional comments about closing:  Committed as r14443
Comment by Robert Keevil (obo) - Sunday, 11 February 2007, 12:18 GMT
Can any Devs/coders with an Archos help? Without a target to test on I don't know how to go about solving this.
Comment by moscow-tyger (moscow-tyger) - Tuesday, 19 June 2007, 12:28 GMT
Is this still untested? I have an Archos v1 recorder and have recently updated from Rockbox 2.4 to make use of the Last.fm log. It appeared to intermittently log a few tracks on one attempt, but after updating the software to the latest daily build, it doesn't seem to even create the .scrobbler.log file.

What do I need to do to test the patch? (Apart from http://www.rockbox.org/twiki/bin/view/Main/SimpleGuideToCompiling )?
Comment by Robert Keevil (obo) - Tuesday, 19 June 2007, 12:49 GMT
The attached patches don't actually solve the problem, they just help to illustrate where the issue is originating. There is currently no fix for the Archos platforms.
Comment by moscow-tyger (moscow-tyger) - Tuesday, 19 June 2007, 12:55 GMT
OK - I'll try to set up a development environment. What should I be looking out for once I get the patch installed?
Comment by moscow-tyger (moscow-tyger) - Thursday, 21 June 2007, 12:34 GMT
I've been able to set up a development environment, which compiles the current build OK. However, the patches won't apply any more ...

[rockbox]$ patch --binary -p0 < /tmp/debug-log.patch
patching file apps/scrobbler.c
Hunk #1 succeeded at 189 with fuzz 1 (offset 3 lines).
[rockbox]$ patch --binary -p0 < /tmp/debug-menu.patch
patching file apps/debug_menu.c
Hunk #1 succeeded at 49 (offset 2 lines).
Hunk #2 FAILED at 2300.
Hunk #3 succeeded at 2379 with fuzz 2 (offset -66 lines).
1 out of 3 hunks FAILED -- saving rejects to file apps/debug_menu.c.rej
patching file apps/scrobbler.c
Hunk #1 succeeded at 301 (offset 40 lines).
patching file apps/scrobbler.h

I tried going back in time to builds from 12246 to 13000 but they each failed at compile time with

/usr/local/sh-elf/lib/gcc/sh-elf/4.0.3/../../../../sh-elf/bin/ld: region FLASH
is full (/home/dcl/rockold/build/apps/rombox.elf section .rodata)
collect2: ld returned 1 exit status

Any thoughts on what I can do next?

Do you think that we'll be able to get the last.fm logger working with HWCODEC at all?


Comment by Boris Gjenero (dreamlayers) - Sunday, 19 August 2007, 00:41 GMT
In apps/main.c toward the end of init(), scrobbler_init() is called before audio_init().

This is okay on SWCODEC platforms because in apps/playback.c track_changed_callback is initially set to NULL by it's declaration:
void (*track_changed_callback)(struct mp3entry *id3) = NULL;

However, my Archos V2 recorder doesn't use apps/playback.c and instead uses firmware/mpeg.c. There the variable is uninitialized in the declaration and instead set to NULL in audio_init(). So, scrobbler_init sets track_changed_callback to scrobbler_change_event via audio_set_track_changed_event, but then audio_init sets it to NULL and scrobbler_change_event doesn't get called.

I changed firmware/mpeg.c to initialize the variable in its declaration like in apps/playback.c and deleted the line that set track_changed_callback to NULL in audio_init(). I played a track for a while and /.scrobbler.log appeared properly. I didn't do any further testing yet.

It might make more sense to instead call scrobbler_init after audio_init in apps/main.c but I felt the change I made was simpler and therefore safer.
Comment by Boris Gjenero (dreamlayers) - Sunday, 19 August 2007, 04:27 GMT
One time several tracks I skipped over were saved as L (listened) so there may be another bug. Skipped tracks are generally saved as S though and I haven't been able to replicate this problem.
Comment by Boris Gjenero (dreamlayers) - Sunday, 19 August 2007, 18:16 GMT
It appears the logging of skipped tracks as listened sometimes happens because in firmware/mpeg.c there are two ways to send a track_changed_callback:
1) In the track_change() function. Here prev_track_elapsed is updated before the callback, and so the scrobbler code sees the proper elapsed value for the previous track.
2) In start_playback_if_ready(). Here prev_track_elapsed is NOT updated, so the scrobbler code sees the elapsed time from the last track which was ended via the track_change() function.

Sometimes method 1 is used and sometimes method 2. For example when skipping to the next track method 1 is used if a part of it is in memory and method 2 if it needs to be read from disk.

This is a bit trickier to fix. I need to figure out how to get reliable elapsed time from the previous track. It would be better if someone more familiar with mpeg.c made this fix. I'll try anyways and will provide a patch if it passes some testing.
Comment by Boris Gjenero (dreamlayers) - Monday, 20 August 2007, 02:56 GMT
Here's my patch for the prev_track_elapsed issue. I took the "Stop the current stream" code for MPEG_PLAY, MPEG_NEXT when a disk read is necessary and MPEG_PREV and put that into a new function end_current_track(). Then in both stop_playing() and end_current_track() I added code to update prev_track_elapsed. This seems to work and it decreases code size.

Now I see another problem: last.fm logging is broken when playing an MP3 with a cue sheet. I haven't investigated this extensively and I don't know if it's ha HWCODEC issue or a general problem. It seems the whole file gets logged and then sometimes individual tracks get logged but without names.
Comment by Boris Gjenero (dreamlayers) - Monday, 20 August 2007, 04:11 GMT
The submission of individual tracks from the cue was due to a bug. In firmware/mpeg.c the 2nd place where track_changed_callback is called, in start_playback_if_ready(), is reached whenever Rockbox needs to read from the HD to start playing from a new location. This included seeks within the same track. I created a new variable play_pending_track_change which differentiates a track change from play_pending being set due to a seek.

I would like to submit individual tracks from the cue (instead of just submitting the MP3), but this would require quite a bit more work, probably not even related to HWCODEC targets. I think that's outside the scope of this bug report.
Comment by moscow-tyger (moscow-tyger) - Monday, 20 August 2007, 19:53 GMT

I've applied these patches to today's SVN version. It compiled and installed correctly on my Jukebox Recorder v1. It also correctly built a .scrobbler.log of the three songs I listend to - and marked the fourth one with an S when I stopped it a few seconds in.

Thank you so much - I really appreciate this.

Is there anything else we need to do for the patch to be submitted?

Comment by Boris Gjenero (dreamlayers) - Monday, 20 August 2007, 22:21 GMT
The only other concern I can think of at the moment is that this doesn't follow last.fm rules regarding seeking through the track. As far as I can see this isn't a HWCODEC based issue however.

The rules can be found at: http://www.audioscrobbler.net/development/protocol/
V1.2 says: "The track must have been played for a duration of at least 240 seconds or half the track's total length, whichever comes first. Skipping or pausing the track is irrelevant as long as the appropriate amount has been played."
V1.1 says: "If a user seeks (i.e. manually changes position) within a song before the song is due to be submitted, do not submit that song." and "Each song should be posted to the server when it is 50% or 240 seconds complete, whichever comes first."

Currently, apps/scrobbler.c seems to check that the track started playing less than halfway through and that the position when it ended playing is past half. This is wrong in various cases, eg.
- resume at 49%, stop at 51% => listened
- fast forward over most of the track => listened
- listen to almost whole track, then seek back to the start and change track => skipped

It would be easy to implement V1.1 and V1.2 would take just a bit more work.
Comment by Robert Keevil (obo) - Wednesday, 22 August 2007, 22:18 GMT
Hi Boris - nice work!

A few notes about the protocol 1.1/1.2 issues: scrobbler support was written against the specification at http://www.audioscrobbler.net/wiki/Portable_Player_Logging rather than the submission protocols (although the timeless bits aren't official).

At the time it was envisioned that the official last.fm client would be extended to handle the log file, submitting back using a custom protocol for hardware players. The closest they've got to this is the undocumented bootstrap protocol (mentioned on the protocol 1.2 page), which IIRC uses zipped XML data. From my own point of view I don't see the need to be too strict when checking the tracks - ultimately a user could edit the log file themselves...