fix: Debug logging level does not persist to disk

This commit is contained in:
ronaldheft
2022-09-08 20:09:35 -04:00
parent cc4c9787c0
commit f8836be147
3 changed files with 30 additions and 34 deletions
+19 -19
View File
@@ -87,10 +87,10 @@ class AudioPlayer: NSObject {
} }
self.currentTrackIndex = getItemIndexForTime(time: playbackSession.currentTime) self.currentTrackIndex = getItemIndexForTime(time: playbackSession.currentTime)
logger.debug("Starting track index \(self.currentTrackIndex) for start time \(playbackSession.currentTime)") logger.log("Starting track index \(self.currentTrackIndex) for start time \(playbackSession.currentTime)")
let playerItems = self.allPlayerItems[self.currentTrackIndex..<self.allPlayerItems.count] let playerItems = self.allPlayerItems[self.currentTrackIndex..<self.allPlayerItems.count]
logger.debug("Setting player items \(playerItems.count)") logger.log("Setting player items \(playerItems.count)")
for item in Array(playerItems) { for item in Array(playerItems) {
self.audioPlayer.insert(item, after:self.audioPlayer.items().last) self.audioPlayer.insert(item, after:self.audioPlayer.items().last)
@@ -100,7 +100,7 @@ class AudioPlayer: NSObject {
setupQueueObserver() setupQueueObserver()
setupQueueItemStatusObserver() setupQueueItemStatusObserver()
logger.debug("Audioplayer ready") logger.log("Audioplayer ready")
} }
deinit { deinit {
@@ -215,14 +215,14 @@ class AudioPlayer: NSObject {
self.audioPlayer.currentItem.map { item in self.audioPlayer.currentItem.map { item in
self.currentTrackIndex = self.allPlayerItems.firstIndex(of:item) ?? 0 self.currentTrackIndex = self.allPlayerItems.firstIndex(of:item) ?? 0
if (self.currentTrackIndex != prevTrackIndex) { if (self.currentTrackIndex != prevTrackIndex) {
self.logger.debug("New Current track index \(self.currentTrackIndex)") self.logger.log("New Current track index \(self.currentTrackIndex)")
} }
} }
} }
} }
private func setupQueueItemStatusObserver() { private func setupQueueItemStatusObserver() {
logger.debug("queueStatusObserver: Setting up") logger.log("queueStatusObserver: Setting up")
// Listen for player item updates // Listen for player item updates
self.queueItemStatusObserver?.invalidate() self.queueItemStatusObserver?.invalidate()
@@ -237,13 +237,13 @@ class AudioPlayer: NSObject {
} }
private func handleQueueItemStatus(playerItem: AVPlayerItem) { private func handleQueueItemStatus(playerItem: AVPlayerItem) {
logger.debug("queueStatusObserver: Current item status changed") logger.log("queueStatusObserver: Current item status changed")
guard let playbackSession = self.getPlaybackSession() else { guard let playbackSession = self.getPlaybackSession() else {
NotificationCenter.default.post(name: NSNotification.Name(PlayerEvents.failed.rawValue), object: nil) NotificationCenter.default.post(name: NSNotification.Name(PlayerEvents.failed.rawValue), object: nil)
return return
} }
if (playerItem.status == .readyToPlay) { if (playerItem.status == .readyToPlay) {
logger.debug("queueStatusObserver: Current Item Ready to play. PlayWhenReady: \(self.playWhenReady)") logger.log("queueStatusObserver: Current Item Ready to play. PlayWhenReady: \(self.playWhenReady)")
// Seek the player before initializing, so a currentTime of 0 does not appear in MediaProgress / session // Seek the player before initializing, so a currentTime of 0 does not appear in MediaProgress / session
let firstReady = self.status < 0 let firstReady = self.status < 0
@@ -271,7 +271,7 @@ class AudioPlayer: NSObject {
guard self.pausedTimer == nil else { return } guard self.pausedTimer == nil else { return }
self.queue.async { self.queue.async {
self.pausedTimer = Timer.scheduledTimer(withTimeInterval: 10, repeats: true) { [weak self] timer in self.pausedTimer = Timer.scheduledTimer(withTimeInterval: 10, repeats: true) { [weak self] timer in
self?.logger.debug("PAUSE TIMER: Syncing from server") self?.logger.log("PAUSE TIMER: Syncing from server")
Task { await PlayerProgress.shared.syncFromServer() } Task { await PlayerProgress.shared.syncFromServer() }
} }
} }
@@ -332,7 +332,7 @@ class AudioPlayer: NSObject {
} }
private func resumePlayback() { private func resumePlayback() {
logger.debug("PLAY: Resuming playback") logger.log("PLAY: Resuming playback")
// Stop the paused timer // Stop the paused timer
self.stopPausedTimer() self.stopPausedTimer()
@@ -349,7 +349,7 @@ class AudioPlayer: NSObject {
public func pause() { public func pause() {
guard self.isInitialized() else { return } guard self.isInitialized() else { return }
logger.debug("PAUSE: Pausing playback") logger.log("PAUSE: Pausing playback")
self.audioPlayer.pause() self.audioPlayer.pause()
self.markAudioSessionAs(active: false) self.markAudioSessionAs(active: false)
@@ -371,17 +371,17 @@ class AudioPlayer: NSObject {
self.pause() self.pause()
logger.debug("SEEK: Seek to \(to) from \(from)") logger.log("SEEK: Seek to \(to) from \(from)")
guard let playbackSession = self.getPlaybackSession() else { return } guard let playbackSession = self.getPlaybackSession() else { return }
let currentTrack = playbackSession.audioTracks[self.currentTrackIndex] let currentTrack = playbackSession.audioTracks[self.currentTrackIndex]
let ctso = currentTrack.startOffset ?? 0.0 let ctso = currentTrack.startOffset ?? 0.0
let trackEnd = ctso + currentTrack.duration let trackEnd = ctso + currentTrack.duration
logger.debug("SEEK: Seek current track END = \(trackEnd)") logger.log("SEEK: Seek current track END = \(trackEnd)")
let indexOfSeek = getItemIndexForTime(time: to) let indexOfSeek = getItemIndexForTime(time: to)
logger.debug("SEEK: Seek to index \(indexOfSeek) | Current index \(self.currentTrackIndex)") logger.log("SEEK: Seek to index \(indexOfSeek) | Current index \(self.currentTrackIndex)")
// Reconstruct queue if seeking to a different track // Reconstruct queue if seeking to a different track
if (self.currentTrackIndex != indexOfSeek) { if (self.currentTrackIndex != indexOfSeek) {
@@ -402,13 +402,13 @@ class AudioPlayer: NSObject {
setupQueueItemStatusObserver() setupQueueItemStatusObserver()
} else { } else {
logger.debug("SEEK: Seeking in current item \(to)") logger.log("SEEK: Seeking in current item \(to)")
let currentTrackStartOffset = playbackSession.audioTracks[self.currentTrackIndex].startOffset ?? 0.0 let currentTrackStartOffset = playbackSession.audioTracks[self.currentTrackIndex].startOffset ?? 0.0
let seekTime = to - currentTrackStartOffset let seekTime = to - currentTrackStartOffset
self.audioPlayer.seek(to: CMTime(seconds: seekTime, preferredTimescale: 1000)) { [weak self] completed in self.audioPlayer.seek(to: CMTime(seconds: seekTime, preferredTimescale: 1000)) { [weak self] completed in
guard completed else { guard completed else {
self?.logger.debug("SEEK: WARNING: seeking not completed (to \(seekTime)") self?.logger.log("SEEK: WARNING: seeking not completed (to \(seekTime)")
return return
} }
guard let self = self else { return } guard let self = self else { return }
@@ -426,7 +426,7 @@ class AudioPlayer: NSObject {
let playbackSpeedChanged = rate > 0.0 && rate != self.tmpRate && !(observed && rate == 1) let playbackSpeedChanged = rate > 0.0 && rate != self.tmpRate && !(observed && rate == 1)
if self.audioPlayer.rate != rate { if self.audioPlayer.rate != rate {
logger.debug("setPlaybakRate rate changed from \(self.audioPlayer.rate) to \(rate)") logger.log("setPlaybakRate rate changed from \(self.audioPlayer.rate) to \(rate)")
self.audioPlayer.rate = rate self.audioPlayer.rate = rate
} }
@@ -481,7 +481,7 @@ class AudioPlayer: NSObject {
} else if (playbackSession.playMethod == PlayMethod.local.rawValue) { } else if (playbackSession.playMethod == PlayMethod.local.rawValue) {
guard let localFile = track.getLocalFile() else { guard let localFile = track.getLocalFile() else {
// Worst case we can stream the file // Worst case we can stream the file
logger.debug("Unable to play local file. Resulting to streaming \(track.localFileId ?? "Unknown")") logger.log("Unable to play local file. Resulting to streaming \(track.localFileId ?? "Unknown")")
let filename = track.metadata?.filename ?? "" let filename = track.metadata?.filename ?? ""
let filenameEncoded = filename.addingPercentEncoding(withAllowedCharacters: NSCharacterSet.urlQueryAllowed) let filenameEncoded = filename.addingPercentEncoding(withAllowedCharacters: NSCharacterSet.urlQueryAllowed)
let urlstr = "\(Store.serverConfig!.address)/s/item/\(itemId)/\(filenameEncoded ?? "")?token=\(Store.serverConfig!.token)" let urlstr = "\(Store.serverConfig!.address)/s/item/\(itemId)/\(filenameEncoded ?? "")?token=\(Store.serverConfig!.token)"
@@ -641,11 +641,11 @@ class AudioPlayer: NSObject {
public override func observeValue(forKeyPath keyPath: String?, of object: Any?, change: [NSKeyValueChangeKey : Any]?, context: UnsafeMutableRawPointer?) { public override func observeValue(forKeyPath keyPath: String?, of object: Any?, change: [NSKeyValueChangeKey : Any]?, context: UnsafeMutableRawPointer?) {
if context == &playerContext { if context == &playerContext {
if keyPath == #keyPath(AVPlayer.rate) { if keyPath == #keyPath(AVPlayer.rate) {
logger.debug("playerContext observer player rate") logger.log("playerContext observer player rate")
self.setPlaybackRate(change?[.newKey] as? Float ?? 1.0, observed: true) self.setPlaybackRate(change?[.newKey] as? Float ?? 1.0, observed: true)
} else if keyPath == #keyPath(AVPlayer.currentItem) { } else if keyPath == #keyPath(AVPlayer.currentItem) {
NotificationCenter.default.post(name: NSNotification.Name(PlayerEvents.update.rawValue), object: nil) NotificationCenter.default.post(name: NSNotification.Name(PlayerEvents.update.rawValue), object: nil)
logger.debug("WARNING: Item ended") logger.log("WARNING: Item ended")
} }
} else { } else {
super.observeValue(forKeyPath: keyPath, of: object, change: change, context: context) super.observeValue(forKeyPath: keyPath, of: object, change: change, context: context)
+9 -9
View File
@@ -98,7 +98,7 @@ class PlayerProgress {
try localMediaProgress.updateFromPlaybackSession(session) try localMediaProgress.updateFromPlaybackSession(session)
logger.debug("Local progress saved to the database") logger.log("Local progress saved to the database")
// Send the local progress back to front-end // Send the local progress back to front-end
NotificationCenter.default.post(name: NSNotification.Name(PlayerEvents.localProgress.rawValue), object: nil) NotificationCenter.default.post(name: NSNotification.Name(PlayerEvents.localProgress.rawValue), object: nil)
@@ -143,7 +143,7 @@ class PlayerProgress {
session = session.freeze() session = session.freeze()
guard safeToSync else { return } guard safeToSync else { return }
logger.debug("Sending sessionId(\(session.id)) to server with currentTime(\(session.currentTime))") logger.log("Sending sessionId(\(session.id)) to server with currentTime(\(session.currentTime))")
var success = false var success = false
if session.isLocal { if session.isLocal {
@@ -163,25 +163,25 @@ class PlayerProgress {
} }
private func updateLocalSessionFromServerMediaProgress() async throws { private func updateLocalSessionFromServerMediaProgress() async throws {
logger.debug("updateLocalSessionFromServerMediaProgress: Checking if local media progress was updated on server") logger.log("updateLocalSessionFromServerMediaProgress: Checking if local media progress was updated on server")
guard let session = try await Realm().objects(PlaybackSession.self).last(where: { guard let session = try await Realm().objects(PlaybackSession.self).last(where: {
$0.isActiveSession == true && $0.serverConnectionConfigId == Store.serverConfig?.id $0.isActiveSession == true && $0.serverConnectionConfigId == Store.serverConfig?.id
})?.freeze() else { })?.freeze() else {
logger.debug("updateLocalSessionFromServerMediaProgress: Failed to get session") logger.log("updateLocalSessionFromServerMediaProgress: Failed to get session")
return return
} }
// Fetch the current progress // Fetch the current progress
let progress = await ApiClient.getMediaProgress(libraryItemId: session.libraryItemId!, episodeId: session.episodeId) let progress = await ApiClient.getMediaProgress(libraryItemId: session.libraryItemId!, episodeId: session.episodeId)
guard let progress = progress else { guard let progress = progress else {
logger.debug("updateLocalSessionFromServerMediaProgress: No progress object") logger.log("updateLocalSessionFromServerMediaProgress: No progress object")
return return
} }
// Determine which session is newer // Determine which session is newer
let serverLastUpdate = progress.lastUpdate let serverLastUpdate = progress.lastUpdate
guard let localLastUpdate = session.updatedAt else { guard let localLastUpdate = session.updatedAt else {
logger.debug("updateLocalSessionFromServerMediaProgress: No local session updatedAt") logger.log("updateLocalSessionFromServerMediaProgress: No local session updatedAt")
return return
} }
let serverCurrentTime = progress.currentTime let serverCurrentTime = progress.currentTime
@@ -192,16 +192,16 @@ class PlayerProgress {
// Update the session, if needed // Update the session, if needed
if serverIsNewerThanLocal && currentTimeIsDifferent { if serverIsNewerThanLocal && currentTimeIsDifferent {
logger.debug("updateLocalSessionFromServerMediaProgress: Server has newer time than local serverLastUpdate=\(serverLastUpdate) localLastUpdate=\(localLastUpdate)") logger.log("updateLocalSessionFromServerMediaProgress: Server has newer time than local serverLastUpdate=\(serverLastUpdate) localLastUpdate=\(localLastUpdate)")
guard let session = session.thaw() else { return } guard let session = session.thaw() else { return }
try session.update { try session.update {
session.currentTime = serverCurrentTime session.currentTime = serverCurrentTime
session.updatedAt = serverLastUpdate session.updatedAt = serverLastUpdate
} }
logger.debug("updateLocalSessionFromServerMediaProgress: Updated session currentTime newCurrentTime=\(serverCurrentTime) previousCurrentTime=\(localCurrentTime)") logger.log("updateLocalSessionFromServerMediaProgress: Updated session currentTime newCurrentTime=\(serverCurrentTime) previousCurrentTime=\(localCurrentTime)")
PlayerHandler.seek(amount: session.currentTime) PlayerHandler.seek(amount: session.currentTime)
} else { } else {
logger.debug("updateLocalSessionFromServerMediaProgress: Local session does not need updating; local has latest progress") logger.log("updateLocalSessionFromServerMediaProgress: Local session does not need updating; local has latest progress")
} }
} }
+2 -6
View File
@@ -52,16 +52,12 @@ public extension AppLogger {
func log(_ information: String, isPrivate: Bool = Defaults.isPrivate) { func log(_ information: String, isPrivate: Bool = Defaults.isPrivate) {
if isPrivate { if isPrivate {
logger.debug("\(information, privacy: .private)") logger.log("\(information, privacy: .private)")
} else { } else {
logger.debug("\(information, privacy: .public)") logger.log("\(information, privacy: .public)")
} }
} }
func debug(_ information: String, isPrivate: Bool = Defaults.isPrivate) {
self.log(information, isPrivate: isPrivate)
}
func error(_ information: String, isPrivate: Bool = Defaults.isPrivate) { func error(_ information: String, isPrivate: Bool = Defaults.isPrivate) {
if isPrivate { if isPrivate {
logger.error("\(information, privacy: .private)") logger.error("\(information, privacy: .private)")