Setup ExtractorLogger in MainActivity

Improve logging in InfoCache.java and elsewhere
Log state name in some methods
Minor refactoring

Author: absurdlylongusername

app/src/main/java/org/schabi/newpipe/MainActivity.java

@@ -69,6 +69,8 @@
 import org.schabi.newpipe.extractor.comments.CommentsInfoItem;
 import org.schabi.newpipe.extractor.exceptions.ExtractionException;
 import org.schabi.newpipe.extractor.services.peertube.PeertubeInstance;
+import org.schabi.newpipe.extractor.utils.ExtractorLogger;
+import org.schabi.newpipe.extractor.utils.Logger;
 import org.schabi.newpipe.fragments.BackPressable;
 import org.schabi.newpipe.fragments.MainFragment;
 import org.schabi.newpipe.fragments.detail.VideoDetailFragment;
@@ -137,6 +139,29 @@ public class MainActivity extends AppCompatActivity {
     @Override
     protected void onCreate(final Bundle savedInstanceState) {
         if (DEBUG) {
+            // Override Extractor to print to Logcat
+            ExtractorLogger.setLogger(new Logger() {
+                @Override
+                public void debug(final String tag, final String message) {
+                    Log.d(tag, message);
+                }
+
+                @Override
+                public void warn(final String tag, final String message) {
+                    Log.w(tag, message);
+                }
+
+                @Override
+                public void error(final String tag, final String message) {
+                    Log.e(tag, message);
+                }
+
+                @Override
+                public void error(final String tag, final String message, final Throwable t) {
+                    Log.e(tag, message, t);
+                }
+
+            });
             Log.d(TAG, "onCreate() called with: "
                     + "savedInstanceState = [" + savedInstanceState + "]");
         }

app/src/main/java/org/schabi/newpipe/player/Player.java

@@ -732,7 +732,9 @@ private void setRecovery(final int queuePos, final long windowPos) {
         }
 
         if (DEBUG) {
-            Log.d(TAG, "Setting recovery, queue: " + queuePos + ", pos: " + windowPos);
+            final var currentTitle = currentItem != null ? currentItem.getTitle() : "";
+            Log.d(TAG, "Setting recovery, queue: "
+                       + queuePos + "[" + currentTitle + "], pos: " + windowPos);
         }
         playQueue.setRecovery(queuePos, windowPos);
     }
@@ -1071,11 +1073,39 @@ public void onPlayWhenReadyChanged(final boolean playWhenReady, final int reason
         updatePlaybackState(playWhenReady, playbackState);
     }
 
+    public static String exoplayerStateToString(final int playbackState) {
+        return switch (playbackState) {
+            case com.google.android.exoplayer2.Player.STATE_IDLE -> // 1
+                    "STATE_IDLE";
+            case com.google.android.exoplayer2.Player.STATE_BUFFERING -> // 2
+                    "STATE_BUFFERING";
+            case com.google.android.exoplayer2.Player.STATE_READY -> //3
+                    "STATE_READY";
+            case com.google.android.exoplayer2.Player.STATE_ENDED -> // 4
+                    "STATE_ENDED";
+            default ->
+                    throw new IllegalArgumentException("Unknown playback state " + playbackState);
+        };
+    }
+
+    public static String stateToString(final int state) {
+        return switch (state) {
+            case STATE_PREFLIGHT -> "STATE_PREFLIGHT";
+            case STATE_BLOCKED -> "STATE_BLOCKED";
+            case STATE_PLAYING -> "STATE_PLAYING";
+            case STATE_BUFFERING -> "STATE_BUFFERING";
+            case STATE_PAUSED -> "STATE_PAUSED";
+            case STATE_PAUSED_SEEK -> "STATE_PAUSED_SEEK";
+            case STATE_COMPLETED -> "STATE_COMPLETED";
+            default -> throw new IllegalArgumentException("Unknown playback state " + state);
+        };
+    }
+
     @Override
     public void onPlaybackStateChanged(final int playbackState) {
         if (DEBUG) {
             Log.d(TAG, "ExoPlayer - onPlaybackStateChanged() called with: "
-                    + "playbackState = [" + playbackState + "]");
+                    + "playbackState = [" + exoplayerStateToString(playbackState) + "]");
         }
         updatePlaybackState(getPlayWhenReady(), playbackState);
     }
@@ -1162,7 +1192,8 @@ public void onPlaybackUnblock(final MediaSource mediaSource) {
 
     public void changeState(final int state) {
         if (DEBUG) {
-            Log.d(TAG, "changeState() called with: state = [" + state + "]");
+            Log.d(TAG,
+                  "changeState() called with: state = [" + stateToString(state) + "]");
         }
         currentState = state;
         switch (state) {
@@ -1882,7 +1913,7 @@ private void saveStreamProgressState(final long progressMillis) {
                     .observeOn(AndroidSchedulers.mainThread())
                     .doOnError(e -> {
                         if (DEBUG) {
-                            e.printStackTrace();
+                            Log.e(TAG, "Error saving stream state", e);
                         }
                     })
                     .onErrorComplete()

app/src/main/java/org/schabi/newpipe/player/datasource/NonUriHlsDataSourceFactory.java

@@ -112,7 +112,7 @@ private NonUriHlsDataSourceFactory(@NonNull final DataSource.Factory dataSourceF
      * </p>
      *
      * <p>
-     * This change allow playback of non-URI HLS contents, when the manifest is not a master
+     * This change allows playback of non-URI HLS contents, when the manifest is not a master
      * manifest/playlist (otherwise, endless loops should be encountered because the
      * {@link DataSource}s created for media playlists should use the master playlist response
      * instead).

app/src/main/java/org/schabi/newpipe/player/mediasession/MediaSessionPlayerUi.java

@@ -36,7 +36,7 @@
 
 public class MediaSessionPlayerUi extends PlayerUi
         implements SharedPreferences.OnSharedPreferenceChangeListener {
-    private static final String TAG = "MediaSessUi";
+    private static final String TAG = MediaSessionPlayerUi.class.getSimpleName();
 
     @NonNull
     private final MediaSessionCompat mediaSession;

app/src/main/java/org/schabi/newpipe/player/playback/MediaSourceManager.java

@@ -9,6 +9,7 @@
 
 import org.reactivestreams.Subscriber;
 import org.reactivestreams.Subscription;
+import org.schabi.newpipe.extractor.StreamingServiceId;
 import org.schabi.newpipe.extractor.exceptions.ExtractionException;
 import org.schabi.newpipe.player.mediaitem.MediaItemTag;
 import org.schabi.newpipe.player.mediasource.FailedMediaSource;
@@ -114,6 +115,9 @@ public class MediaSourceManager {
 
     @NonNull
     private final CompositeDisposable loaderReactor;
+    /**
+     * The items that are currently being loaded.
+     */
     @NonNull
     private final Set<PlayQueueItem> loadingItems;
 
@@ -146,6 +150,20 @@ private MediaSourceManager(@NonNull final PlaybackListener listener,
                     + " ms] for them to be useful.");
         }
 
+        if (DEBUG) {
+            final var currentItem = playQueue.getItem();
+
+            if (currentItem != null) {
+                Log.d(TAG, "Creating MediaSourceManager["
+                           + StreamingServiceId.nameFromId(currentItem.getServiceId())
+                           + " currentIndex=" + playQueue.getIndex()
+                           + " currentTitle=" + currentItem.getTitle());
+            } else {
+                Log.d(TAG,
+                      "Creating MediaSourceManager[currentIndex=" + playQueue.getIndex() + "]");
+            }
+        }
+
         this.playbackListener = listener;
         this.playQueue = playQueue;
 
@@ -180,13 +198,15 @@ private MediaSourceManager(@NonNull final PlaybackListener listener,
      */
     public void dispose() {
         if (DEBUG) {
-            Log.d(TAG, "close() called.");
+            Log.d(TAG, "dispose() called.");
         }
 
         debouncedSignal.onComplete();
         debouncedLoader.dispose();
 
         playQueueReactor.cancel();
+        //TODO: Why not clear here?
+        //TODO: Also why not clear loadingItems here?
         loaderReactor.dispose();
     }
 
@@ -427,6 +447,11 @@ private Single<ManagedMediaSource> getLoadedMediaSource(@NonNull final PlayQueue
                                 MediaItemTag.from(source.getMediaItem())
                                         .map(tag -> {
                                             final int serviceId = streamInfo.getServiceId();
+                                            // CHECKSTYLE:OFF
+    // TODO: So this expiration is false. Expiration starts from when stream is extracted
+    //  But here it is giving it fresh expiration as though the stream info is new, but it's not
+    //  So cache expiration is not 1-1 with stream expiration, but is it supposed to be?
+                                            // CHECKSTYLE:ON
                                             final long expiration = System.currentTimeMillis()
                                                     + getCacheExpirationMillis(serviceId);
                                             return new LoadedMediaSource(source, tag, stream,
@@ -483,7 +508,7 @@ private void onMediaSourceReceived(@NonNull final PlayQueueItem item,
      * readiness or playlist desynchronization.
      * <p>
      * If the given {@link PlayQueueItem} is currently being played and is already loaded,
-     * then correction is not only needed if the playlist is desynchronized. Otherwise, the
+     * then correction is only needed if the playlist is desynchronized. Otherwise, the
      * check depends on the status (e.g. expiration or placeholder) of the
      * {@link ManagedMediaSource}.
      * </p>
@@ -530,10 +555,12 @@ private void maybeRenewCurrentIndex() {
     }
 
     private void maybeClearLoaders() {
+        final var currentItem = playQueue.getItem();
         if (DEBUG) {
-            Log.d(TAG, "MediaSource - maybeClearLoaders() called.");
+            final var url = currentItem != null ? currentItem.getUrl() : "";
+            Log.d(TAG, "MediaSource - maybeClearLoaders() called. currentItem: " + url);
         }
-        if (!loadingItems.contains(playQueue.getItem())
+        if (!loadingItems.contains(currentItem)
                 && loaderReactor.size() > MAXIMUM_LOADER_SIZE) {
             loaderReactor.clear();
             loadingItems.clear();

app/src/main/java/org/schabi/newpipe/player/playqueue/PlayQueue.java

@@ -552,11 +552,8 @@ public boolean equalStreams(@Nullable final PlayQueue other) {
     }
 
     public boolean equalStreamsAndIndex(@Nullable final PlayQueue other) {
-        if (equalStreams(other)) {
-            //noinspection ConstantConditions
-            return other.getIndex() == getIndex(); //NOSONAR: other is not null
-        }
-        return false;
+        //noinspection ConstantConditions
+        return equalStreams(other) && other.getIndex() == getIndex(); //NOSONAR: other is not null
     }
 
     public boolean isDisposed() {

app/src/main/java/org/schabi/newpipe/util/InfoCache.java

@@ -27,8 +27,11 @@
 
 import org.schabi.newpipe.MainActivity;
 import org.schabi.newpipe.extractor.Info;
+import org.schabi.newpipe.extractor.StreamingServiceId;
 
-import java.util.Map;
+import java.time.Instant;
+import java.time.LocalDateTime;
+import java.time.ZoneId;
 
 public final class InfoCache {
     private final String TAG = getClass().getSimpleName();
@@ -71,23 +74,24 @@ private static String keyOf(final int serviceId,
     }
 
     private static void removeStaleCache() {
-        for (final Map.Entry<String, CacheData> entry : InfoCache.LRU_CACHE.snapshot().entrySet()) {
+        for (final var entry : LRU_CACHE.snapshot().entrySet()) {
             final CacheData data = entry.getValue();
             if (data != null && data.isExpired()) {
-                InfoCache.LRU_CACHE.remove(entry.getKey());
+                LRU_CACHE.remove(entry.getKey());
             }
         }
     }
 
     @Nullable
     private static Info getInfo(@NonNull final String key) {
-        final CacheData data = InfoCache.LRU_CACHE.get(key);
+        final CacheData data = LRU_CACHE.get(key);
         if (data == null) {
             return null;
         }
 
         if (data.isExpired()) {
-            InfoCache.LRU_CACHE.remove(key);
+            // TODO: oh so we do check expiry on retrieval!
+            LRU_CACHE.remove(key);
             return null;
         }
 
@@ -100,22 +104,32 @@ public Info getFromKey(final int serviceId,
                            @NonNull final Type cacheType) {
         if (DEBUG) {
             Log.d(TAG, "getFromKey() called with: "
-                    + "serviceId = [" + serviceId + "], url = [" + url + "]");
+                    + StreamingServiceId.nameFromId(serviceId) + "[" + url + "]");
         }
         synchronized (LRU_CACHE) {
             return getInfo(keyOf(serviceId, url, cacheType));
         }
     }
 
+    @SuppressWarnings("checkStyle:linelength")
     public void putInfo(final int serviceId,
                         @NonNull final String url,
                         @NonNull final Info info,
                         @NonNull final Type cacheType) {
+        final long expirationMillis = ServiceHelper.getCacheExpirationMillis(info.getServiceId());
+        // CHECKSTYLE:OFF
+        // TODO: Expired items get refreshed by being put again; they are not removed when they expire
+        // CHECKSTYLE:ON
         if (DEBUG) {
-            Log.d(TAG, "putInfo() called with: info = [" + info + "]");
+            final var expiryDateInstant = Instant.now().plusMillis(expirationMillis);
+            final var expiryDate = LocalDateTime.ofInstant(expiryDateInstant,
+                                                           ZoneId.systemDefault());
+            Log.d(TAG, "putInfo(): add to cache " + StreamingServiceId.nameFromId(serviceId) + " "
+                    + cacheType.name()
+                    + " expires on " + expiryDate
+                    + " " + info);
         }
 
-        final long expirationMillis = ServiceHelper.getCacheExpirationMillis(info.getServiceId());
         synchronized (LRU_CACHE) {
             final CacheData data = new CacheData(info, expirationMillis);
             LRU_CACHE.put(keyOf(serviceId, url, cacheType), data);

app/src/main/java/org/schabi/newpipe/util/ListHelper.java

@@ -302,6 +302,9 @@ public static List<AudioStream> getFilteredAudioStreams(
         final Comparator<AudioStream> cmp = getAudioFormatComparator(context);
 
         for (final AudioStream stream : audioStreams) {
+            // TODO: this doesn't add HLS OPUS streams, but soundcloud has that.
+            // Meaning it never actually plays the OPUS soundcloud streams, only
+            // progressive and hls mp3
             if (stream.getDeliveryMethod() == DeliveryMethod.TORRENT
                     || (stream.getDeliveryMethod() == DeliveryMethod.HLS
                     && stream.getFormat() == MediaFormat.OPUS)) {

app/src/main/java/org/schabi/newpipe/util/SparseItemUtil.java

@@ -32,7 +32,7 @@ private SparseItemUtil() {
     }
 
     /**
-     * Use this to certainly obtain an single play queue with all of the data filled in when the
+     * Use this to certainly obtain a single play queue with all of the data filled in when the
      * stream info item you are handling might be sparse, e.g. because it was fetched via a {@link
      * org.schabi.newpipe.extractor.feed.FeedExtractor}. FeedExtractors provide a fast and
      * lightweight method to fetch info, but the info might be incomplete (see