[Feature] playback logging from core

people don't like having to remember to run the TSR plugin so
lets meet them halfway

all tracks are added with timestamp, elapsed, length, trackname

added buffering for ATA devices

still needed:
-Done -- a plugin that parses for duplicates and reads the track info
to create the actual scrobbler log
(log can be truncated once dumped)
this should allow you to run the plugin at leisure

later I'd like to expand this logging to allow
track culling based on skipped songs..

remove the TSR plugin as hard disk no longer need to use it

Change-Id: Ib0b74b4c868fecb3e4941a8f4b9de7bd8728fe3e

apps/playback.c

@@ -46,6 +46,8 @@
 #include "settings.h"
 #include "audiohw.h"
 
+#include <stdio.h>
+
 #ifdef HAVE_TAGCACHE
 #include "tagcache.h"
 #endif
@@ -346,6 +348,11 @@ static int  codec_skip_status;
 static bool codec_seeking = false;          /* Codec seeking ack expected? */
 static unsigned int position_key = 0;
 
+#if (CONFIG_STORAGE & STORAGE_ATA)
+#define PLAYBACK_LOG_BUFSZ (MAX_PATH * 10)
+static int playback_log_handle = 0; /* core_alloc handle for playback log buffer */
+#endif
+
 /* Forward declarations */
 enum audio_start_playback_flags
 {
@@ -1229,6 +1236,104 @@ static void audio_handle_track_load_status(int trackstat)
     }
 }
 
+void allocate_playback_log(void) INIT_ATTR;
+void allocate_playback_log(void)
+{
+#if (CONFIG_STORAGE & STORAGE_ATA)
+    if (global_settings.playback_log && playback_log_handle == 0)
+    {
+        playback_log_handle = core_alloc(PLAYBACK_LOG_BUFSZ);
+        if (playback_log_handle > 0)
+        {
+            DEBUGF("%s Allocated %d bytes\n", __func__, PLAYBACK_LOG_BUFSZ); 
+            char *buf = core_get_data(playback_log_handle);
+            buf[0] = '\0';
+            return;
+        }
+    }
+#endif
+}
+
+void add_playbacklog(struct mp3entry *id3)
+{
+    if (!global_settings.playback_log)
+        return;
+    ssize_t used = 0;
+    unsigned long timestamp = current_tick;
+#if (CONFIG_STORAGE & STORAGE_ATA)
+    char *buf = NULL;
+    ssize_t bufsz;
+
+    /* if the user just enabled playback logging rather than stopping playback
+     * to allocate a buffer or if buffer too large just flush direct to disk
+     * buffer will attempt to be allocated next start-up */
+    if (playback_log_handle > 0)
+    {
+        buf = core_get_data(playback_log_handle);
+        used = strlen(buf);
+        bufsz = PLAYBACK_LOG_BUFSZ - used;
+        buf += used;
+        DEBUGF("%s Used %lu Remain: %lu\n", __func__, used, bufsz);
+    }
+#endif
+    if (id3 && id3->elapsed > 500) /* 500 ms*/
+    {
+#if     CONFIG_RTC
+        timestamp = mktime(get_time());
+#endif
+#if (CONFIG_STORAGE & STORAGE_ATA)
+        if (buf)  /* we have a buffer allocd from core */
+        {
+            /*10:10:10:MAX_PATH\n*/
+            ssize_t entrylen = snprintf(buf, bufsz,"%lu:%ld:%ld:%s\n",
+                    timestamp, (long)id3->elapsed, (long)id3->length, id3->path);
+
+            if (entrylen < bufsz)
+            {
+                DEBUGF("BUFFERED: time: %lu elapsed %ld/%ld saving file: %s\n",
+                                timestamp, id3->elapsed, id3->length, id3->path);
+                return; /* succeed or snprintf fail return */
+            }
+            buf[0] = '\0';
+        }
+        /* that didn't fit, flush buffer & write this entry to disk */
+#endif
+    }
+    else
+        id3 = NULL;
+
+    if (id3 || used > 0) /* flush */
+    {
+        DEBUGF("Opening %s \n", ROCKBOX_DIR "/playback.log");
+        int fd = open(ROCKBOX_DIR "/playback.log", O_WRONLY|O_CREAT|O_APPEND, 0666);
+        if (fd < 0)
+        {
+            return; /* failure */
+        }
+#if (CONFIG_STORAGE & STORAGE_ATA)
+        if (buf) /* we have a buffer allocd from core */
+        {
+            buf = core_get_data_pinned(playback_log_handle); /* we might yield - pin it*/
+            write(fd, buf, used);
+            DEBUGF("%s Writing %lu bytes of buf:\n%s\n", __func__, used, buf);
+            buf[0] = '\0';
+            core_put_data_pinned(buf);
+        }
+#endif
+        if (id3)
+        {
+            /* we have the timestamp from when we tried to add to buffer */
+            DEBUGF("LOGGED: time: %lu elapsed %ld/%ld saving file: %s\n",
+                                timestamp, id3->elapsed, id3->length, id3->path);
+            fdprintf(fd, "%lu:%ld:%ld:%s\n",
+                    timestamp, (long)id3->elapsed, (long)id3->length, id3->path);
+        }
+
+        close(fd);
+        return;
+    }
+}
+
 /* Send track events that use a struct track_event for data */
 static void send_track_event(unsigned int id, unsigned int flags,
                              struct mp3entry *id3)
@@ -1246,9 +1351,9 @@ static void audio_playlist_track_finish(void)
     struct mp3entry *id3 = valid_mp3entry(ply_id3);
 
     playlist_update_resume_info(filling == STATE_ENDED ? NULL : id3);
-
     if (id3)
     {
+        add_playbacklog(id3);
         send_track_event(PLAYBACK_EVENT_TRACK_FINISH,
                          track_event_flags, id3);
     }
@@ -3010,6 +3115,7 @@ static void audio_stop_playback(void)
     /* Go idle */
     filling = STATE_IDLE;
     cancel_cpu_boost();
+    add_playbacklog(NULL);
 }
 
 /* Pause the playback of the current track