Skip to content

Commit

Permalink
Merge branch 'feature/time-tracking-rewrite'
Browse files Browse the repository at this point in the history
  • Loading branch information
io7m committed Oct 17, 2024
2 parents 91e03d5 + c8104b9 commit f68b690
Show file tree
Hide file tree
Showing 51 changed files with 2,480 additions and 1,109 deletions.
9 changes: 7 additions & 2 deletions README-CHANGES.xml
Original file line number Diff line number Diff line change
Expand Up @@ -556,18 +556,23 @@
</c:change>
</c:changes>
</c:release>
<c:release date="2024-10-03T11:19:53+00:00" is-open="true" ticket-system="org.lyrasis.jira" version="1.14.0">
<c:release date="2024-10-17T16:11:02+00:00" is-open="true" ticket-system="org.lyrasis.jira" version="1.14.0">
<c:changes>
<c:change date="2024-10-03T00:00:00+00:00" summary="Repair book previews.">
<c:tickets>
<c:ticket id="PP-1765"/>
</c:tickets>
</c:change>
<c:change date="2024-10-03T11:19:53+00:00" summary="Fix an unlikely crash in the audiobooks toolbar.">
<c:change date="2024-10-03T00:00:00+00:00" summary="Fix an unlikely crash in the audiobooks toolbar.">
<c:tickets>
<c:ticket id="PP-1789"/>
</c:tickets>
</c:change>
<c:change date="2024-10-17T16:11:02+00:00" summary="Rewrite time tracking.">
<c:tickets>
<c:ticket id="PP-1704"/>
</c:tickets>
</c:change>
</c:changes>
</c:release>
</c:releases>
Expand Down
2 changes: 1 addition & 1 deletion org.thepalaceproject.android.platform
3 changes: 3 additions & 0 deletions simplified-app-palace/build.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -525,6 +525,8 @@ dependencies {
implementation(libs.google.material)
implementation(libs.io7m.jfunctional)
implementation(libs.io7m.jnull)
implementation(libs.io7m.jattribute.core)
implementation(libs.io7m.jmulticlose)
implementation(libs.irradia.fieldrush.api)
implementation(libs.irradia.fieldrush.vanilla)
implementation(libs.irradia.mime.api)
Expand Down Expand Up @@ -575,6 +577,7 @@ dependencies {
implementation(libs.palace.audiobook.manifest.parser.webpub)
implementation(libs.palace.audiobook.media3)
implementation(libs.palace.audiobook.parser.api)
implementation(libs.palace.audiobook.time.tracking)
implementation(libs.palace.audiobook.views)
implementation(libs.palace.drm.core)
implementation(libs.palace.http.api)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ import org.librarysimplified.audiobook.license_check.spi.SingleLicenseCheckStatu
import org.librarysimplified.audiobook.manifest.api.PlayerManifest
import org.librarysimplified.audiobook.manifest_fulfill.spi.ManifestFulfilled
import org.librarysimplified.audiobook.manifest_fulfill.spi.ManifestFulfillmentErrorType
import org.librarysimplified.audiobook.manifest_parser.api.ManifestUnparsed
import org.librarysimplified.audiobook.parser.api.ParseError
import org.librarysimplified.audiobook.parser.api.ParseResult
import org.librarysimplified.audiobook.parser.api.ParseWarning
Expand Down Expand Up @@ -239,7 +240,7 @@ abstract class AbstractAudioBookManifestStrategy(
this.logger.debug("parseManifest")
return this.request.manifestParsers.parse(
uri = source,
streams = data,
input = ManifestUnparsed(request.palaceID, data),
extensions = this.request.extensions
)
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package org.nypl.simplified.books.audio
import one.irradia.mime.api.MIMEType
import org.librarysimplified.audiobook.api.PlayerUserAgent
import org.librarysimplified.audiobook.license_check.spi.SingleLicenseCheckProviderType
import org.librarysimplified.audiobook.manifest.api.PlayerPalaceID
import org.librarysimplified.audiobook.manifest_fulfill.api.ManifestFulfillmentStrategies
import org.librarysimplified.audiobook.manifest_fulfill.api.ManifestFulfillmentStrategyRegistryType
import org.librarysimplified.audiobook.manifest_fulfill.spi.ManifestFulfilled
Expand All @@ -21,6 +22,13 @@ import java.util.ServiceLoader

data class AudioBookManifestRequest(

/**
* The book's Palace ID for time tracking. This is essentially delivered as the book's ID
* value in the OPDS feed in which it was delivered.
*/

val palaceID: PlayerPalaceID,

/**
* The audio book file on disk, if one has been downloaded. This is used for packaged audio
* books, where the entire book is downloaded in one file. For unpackaged audio books, where
Expand Down
1 change: 1 addition & 0 deletions simplified-books-borrowing/build.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ dependencies {
implementation(libs.kotlin.stdlib)
implementation(libs.kotlinx.coroutines)
implementation(libs.palace.audiobook.api)
implementation(libs.palace.audiobook.manifest.api)
implementation(libs.palace.audiobook.manifest.fulfill.api)
implementation(libs.palace.audiobook.manifest.fulfill.spi)
implementation(libs.palace.audiobook.manifest.parser.api)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import com.io7m.junreachable.UnreachableCodeException
import one.irradia.mime.api.MIMECompatibility
import one.irradia.mime.api.MIMEType
import org.librarysimplified.audiobook.api.PlayerUserAgent
import org.librarysimplified.audiobook.manifest.api.PlayerPalaceID
import org.nypl.simplified.accounts.api.AccountAuthenticationCredentials
import org.nypl.simplified.accounts.api.AccountReadableType
import org.nypl.simplified.books.audio.AudioBookCredentials
Expand Down Expand Up @@ -131,7 +132,8 @@ class BorrowAudioBook private constructor() : BorrowSubtaskType {
userAgent = PlayerUserAgent(context.httpClient.userAgent()),
credentials = audioBookCredentials,
services = context.services,
cacheDirectory = context.cacheDirectory()
cacheDirectory = context.cacheDirectory(),
palaceID = PlayerPalaceID(context.bookCurrent.entry.id)
)
)

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,9 @@ import org.librarysimplified.audiobook.api.PlayerAudioEngines
import org.librarysimplified.audiobook.api.PlayerResult
import org.librarysimplified.audiobook.api.PlayerUserAgent
import org.librarysimplified.audiobook.manifest.api.PlayerManifest
import org.librarysimplified.audiobook.manifest.api.PlayerPalaceID
import org.librarysimplified.audiobook.manifest_parser.api.ManifestParsers
import org.librarysimplified.audiobook.manifest_parser.api.ManifestUnparsed
import org.librarysimplified.audiobook.parser.api.ParseResult
import org.nypl.simplified.books.api.BookDRMInformation
import org.nypl.simplified.books.api.BookDRMKind
Expand Down Expand Up @@ -166,7 +168,13 @@ internal class DatabaseFormatHandleAudioBook internal constructor(
this.log.debug("[{}]: parsing audio book manifest", briefID)

val manifestResult: ParseResult<PlayerManifest> =
ManifestParsers.parse(this.fileManifest.toURI(), stream.readBytes())
ManifestParsers.parse(
uri = this.fileManifest.toURI(),
input = ManifestUnparsed(
palaceId = PlayerPalaceID(this.parameters.entry.book.entry.id),
data = stream.readBytes()
)
)

when (manifestResult) {
is ParseResult.Failure -> {
Expand Down
38 changes: 38 additions & 0 deletions simplified-books-time-tracking/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -4,3 +4,41 @@ org.librarysimplified.books.time.tracking
The `org.librarysimplified.books.time.tracking` module provides all the code necessary to track
the time a book is being read or listened to.

## Implementation

The time tracking service is split into four components in order to make each step independently
testable and auditable.

1. The audiobook player publishes time spans. A time span is started when the play button is
pressed in an audiobook, and ends after one minute or the pause button is pressed, whichever
comes first. If the pause button _wasn't_ pressed, a new time span is started. This effectively
means that the audiobook player publishes a stream of time spans as long as a book is playing.
Once published, the audiobook player doesn't care what happens to the spans.

2. The _collector_ service subscribes to the audiobook player span stream and serializes each
span to disk in a single directory. Spans are written atomically by creating temporary files
and then atomically renaming the temporary files to a naming pattern recognized by the _merger_.

3. The _merger_ service watches the directory written by the _collector_ and, roughly every
thirty seconds, reads every serialized time span that is older than ninety seconds. The
reason for having the age cutoff is that we want to be absolutely certain that no new spans
will arrive for a given minute before we merge them, so we have to be absolutely sure that
the "most recent minute" is over. The read spans are merged into time tracking entries that
the server expects and atomically written to an output directory.

4. The _sender_ service watches the directory written by the _merger_ and reads time tracking
entries from the directory. It sends each entry to the server (batching the entries to
minimize the number of HTTP calls). For every entry the server claims to have accepted, the
corresponding entry file is deleted from the _merger_ output directory. Entries that were
not accepted are retried indefinitely.

All operations are recorded into an append-only audit log that can be captured from the device
when sending error logs.

Errors are logged to Crashlytics with the following attributes:

|Name|Value|
|----|-----|
|`System`|`TimeTracking`|
|`SubSystem`|One of `Collector`, `Merger`, `Sender`|
|`TimeLoss`|Either `true` or `false` depending on whether the system thinks it lost a time tracking entry|
8 changes: 6 additions & 2 deletions simplified-books-time-tracking/build.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -7,16 +7,20 @@ dependencies {
implementation(project(":simplified-profiles-controller-api"))
implementation(project(":simplified-services-api"))

implementation(libs.azam.ulidj)
implementation(libs.io7m.jmulticlose)
implementation(libs.io7m.jattribute.core)
implementation(libs.irradia.mime.api)
implementation(libs.kotlinx.datetime)
implementation(libs.jackson.core)
implementation(libs.jackson.databind)
implementation(libs.joda.time)
implementation(libs.kotlin.stdlib)
implementation(libs.kotlinx.datetime)
implementation(libs.palace.audiobook.api)
implementation(libs.palace.audiobook.manifest.api)
implementation(libs.palace.audiobook.time.tracking)
implementation(libs.palace.http.api)
implementation(libs.rxandroid2)
implementation(libs.rxjava2)
implementation(libs.slf4j)
implementation(libs.azam.ulidj)
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,195 @@
package org.nypl.simplified.books.time.tracking

import com.io7m.jattribute.core.AttributeReadableType
import com.io7m.jmulticlose.core.CloseableCollection
import io.reactivex.Observable
import org.librarysimplified.audiobook.time_tracking.PlayerTimeTracked
import org.nypl.simplified.profiles.controller.api.ProfilesControllerType
import org.slf4j.LoggerFactory
import org.slf4j.MDC
import java.nio.file.Files
import java.nio.file.Path
import java.nio.file.StandardCopyOption.ATOMIC_MOVE
import java.nio.file.StandardCopyOption.REPLACE_EXISTING
import java.nio.file.StandardOpenOption.CREATE
import java.nio.file.StandardOpenOption.TRUNCATE_EXISTING
import java.nio.file.StandardOpenOption.WRITE
import java.time.ZoneOffset
import java.util.concurrent.Executors
import java.util.concurrent.LinkedBlockingQueue
import java.util.concurrent.TimeUnit

/**
* The collector service.
*
* This listens for a stream of "time tracked" events and serializes them into a directory. It
* also records, for debugging purposes, when time tracking has "started" and "stopped" (ie, a
* book has opened or closed).
*/

class TimeTrackingCollector private constructor(
private val profiles: ProfilesControllerType,
private val status: AttributeReadableType<TimeTrackingStatus>,
private val timeSegments: Observable<PlayerTimeTracked>,
private val debugDirectory: Path,
private val outputDirectory: Path,
) : TimeTrackingCollectorServiceType {

private val logger =
LoggerFactory.getLogger(TimeTrackingCollector::class.java)

private val awaitWrite =
LinkedBlockingQueue<Unit>()
private val resources =
CloseableCollection.create()

private val executor =
Executors.newSingleThreadExecutor { r ->
val thread = Thread(r)
thread.name = "org.nypl.simplified.books.time.tracking.collector[${thread.id}]"
thread.isDaemon = true
thread.priority = Thread.MIN_PRIORITY
thread
}

init {
this.resources.add(AutoCloseable {
this.executor.shutdown()
this.executor.awaitTermination(30L, TimeUnit.SECONDS)
})
val timeSubscription = this.timeSegments.subscribe(this::onTimeTrackedReceived)
this.resources.add(AutoCloseable { timeSubscription.dispose() })
this.resources.add(this.status.subscribe(this::onStatusChanged))
this.resources.add(AutoCloseable { this.awaitWrite.offer(Unit) })
}

private fun onTimeTrackedReceived(
time: PlayerTimeTracked
) {
this.executor.execute { this.saveTimeTracked(time) }
}

private fun saveTimeTracked(
time: PlayerTimeTracked
) {
try {
MDC.put("System", "TimeTracking")
MDC.put("SubSystem", "Collector")
MDC.put("Book", time.bookTrackingId.value)
MDC.put("Seconds", time.seconds.toString())
MDC.remove("TimeLoss")

when (val statusNow = this.status.get()) {
is TimeTrackingStatus.Active -> {
val account = this.profiles.profileCurrent().account(statusNow.accountID)

if (time.bookTrackingId != statusNow.bookId) {
MDC.put("TimeLoss", "true")
this.logger.warn(
"Time loss: Time tracking data received for book {}, but book {} is selected",
statusNow.bookId,
time.bookTrackingId
)
return
}

Files.createDirectories(this.outputDirectory)

val outFile =
this.outputDirectory.resolve("${time.id}.ttspan")
val outFileTmp =
this.outputDirectory.resolve("${time.id}.ttspan.tmp")

val utcStart =
time.timeStarted.withOffsetSameInstant(ZoneOffset.UTC)
val utcEnd =
time.timeEnded.withOffsetSameInstant(ZoneOffset.UTC)

val span =
TimeTrackingReceivedSpan(
id = time.id,
accountID = statusNow.accountID,
libraryID = account.provider.id,
bookID = statusNow.bookId,
timeStarted = utcStart,
timeEnded = utcEnd,
targetURI = statusNow.timeTrackingUri
)

Files.newOutputStream(outFileTmp, WRITE, CREATE, TRUNCATE_EXISTING).use { s ->
span.toProperties().store(s, "")
s.flush()
}
Files.move(outFileTmp, outFile, ATOMIC_MOVE, REPLACE_EXISTING)
}

TimeTrackingStatus.Inactive -> {
MDC.put("TimeLoss", "true")
this.logger.warn(
"Time tracking data received for book {}, but no book is selected",
time.bookTrackingId
)
}
}
} catch (e: Throwable) {
MDC.put("TimeLoss", "true")
this.logger.warn("Failed to save time tracking information: ", e)
} finally {
this.awaitWrite.offer(Unit)
}
}

companion object {
fun create(
profiles: ProfilesControllerType,
status: AttributeReadableType<TimeTrackingStatus>,
timeSegments: Observable<PlayerTimeTracked>,
debugDirectory: Path,
outputDirectory: Path,
): TimeTrackingCollectorServiceType {
return TimeTrackingCollector(
profiles = profiles,
status = status,
timeSegments = timeSegments,
debugDirectory = debugDirectory,
outputDirectory = outputDirectory
)
}
}

private fun onStatusChanged(
oldValue: TimeTrackingStatus,
newValue: TimeTrackingStatus,
) {
when (newValue) {
is TimeTrackingStatus.Active -> {
TimeTrackingDebugging.onTimeTrackingStarted(
timeTrackingDebugDirectory = this.debugDirectory.toFile(),
libraryId = newValue.libraryId,
bookId = newValue.bookId.value
)
}

TimeTrackingStatus.Inactive -> {
if (oldValue is TimeTrackingStatus.Active) {
TimeTrackingDebugging.onTimeTrackingStopped(
timeTrackingDebugDirectory = this.debugDirectory.toFile(),
libraryId = oldValue.libraryId,
bookId = oldValue.bookId.value
)
}
}
}
}

override fun awaitWrite(
timeout: Long,
unit: TimeUnit
) {
this.awaitWrite.poll(timeout, unit)
}

override fun close() {
this.resources.close()
}
}
Loading

0 comments on commit f68b690

Please sign in to comment.