Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: Implement logging for Room, RoomLifecycleManager #84

Merged
merged 3 commits into from
Dec 12, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions chat-android/src/main/java/com/ably/chat/Logger.kt
Original file line number Diff line number Diff line change
Expand Up @@ -94,12 +94,12 @@ internal class AndroidLogger(
override fun log(message: String, level: LogLevel, throwable: Throwable?, newTag: String?, newStaticContext: Map<String, String>) {
if (level.logLevelValue < minimalVisibleLogLevel.logLevelValue) return
val finalContext = context.mergeWith(newTag, newStaticContext)
val tag = finalContext.tag
val tag = "ably-chat:${finalContext.tag}"
val completeContext = finalContext.staticContext + finalContext.dynamicContext.mapValues { it.value() }

val contextString = ", context: $completeContext"
val currentTime = SimpleDateFormat("yyyy-MM-dd HH:mm:ss.S", Locale.US).format(Date())
val formattedMessage = "$currentTime [$tag] (${level.name.uppercase()}) ably-chat: ${message}$contextString"
val formattedMessage = "$currentTime (${level.name.uppercase()}) ${finalContext.tag}:${message}$contextString"
when (level) {
// We use Logcat's info level for Trace and Debug
LogLevel.Trace -> Log.i(tag, formattedMessage, throwable)
Expand Down
4 changes: 2 additions & 2 deletions chat-android/src/main/java/com/ably/chat/Messages.kt
Original file line number Diff line number Diff line change
Expand Up @@ -220,13 +220,13 @@ internal class DefaultMessagesSubscription(

internal class DefaultMessages(
val room: DefaultRoom,
) : Messages, ContributesToRoomLifecycleImpl(room.roomLogger) {
) : Messages, ContributesToRoomLifecycleImpl(room.logger) {

override val featureName: String = "messages"

private var channelStateListener: ChannelStateListener

private val logger = room.roomLogger.withContext(tag = "Messages")
private val logger = room.logger.withContext(tag = "Messages")

private val roomId = room.roomId

Expand Down
4 changes: 2 additions & 2 deletions chat-android/src/main/java/com/ably/chat/Occupancy.kt
Original file line number Diff line number Diff line change
Expand Up @@ -73,15 +73,15 @@ data class OccupancyEvent(

internal class DefaultOccupancy(
private val room: DefaultRoom,
) : Occupancy, ContributesToRoomLifecycleImpl(room.roomLogger) {
) : Occupancy, ContributesToRoomLifecycleImpl(room.logger) {

override val featureName: String = "occupancy"

override val attachmentErrorCode: ErrorCode = ErrorCode.OccupancyAttachmentFailed

override val detachmentErrorCode: ErrorCode = ErrorCode.OccupancyDetachmentFailed

private val logger = room.roomLogger.withContext(tag = "Occupancy")
private val logger = room.logger.withContext(tag = "Occupancy")

override val channel: Channel = room.messages.channel

Expand Down
12 changes: 6 additions & 6 deletions chat-android/src/main/java/com/ably/chat/Presence.kt
Original file line number Diff line number Diff line change
Expand Up @@ -136,7 +136,7 @@ data class PresenceEvent(

internal class DefaultPresence(
private val room: DefaultRoom,
) : Presence, ContributesToRoomLifecycleImpl(room.roomLogger) {
) : Presence, ContributesToRoomLifecycleImpl(room.logger) {

override val featureName = "presence"

Expand All @@ -146,12 +146,12 @@ internal class DefaultPresence(

override val channel: Channel = room.messages.channel

private val logger = room.roomLogger.withContext(tag = "Presence")
private val logger = room.logger.withContext(tag = "Presence")

private val presence = channel.presence

override suspend fun get(waitForSync: Boolean, clientId: String?, connectionId: String?): List<PresenceMember> {
room.ensureAttached() // CHA-PR6d, CHA-PR6c, CHA-PR6h
room.ensureAttached(logger) // CHA-PR6d, CHA-PR6c, CHA-PR6h
return presence.getCoroutine(waitForSync, clientId, connectionId).map { user ->
PresenceMember(
clientId = user.clientId,
Expand All @@ -165,17 +165,17 @@ internal class DefaultPresence(
override suspend fun isUserPresent(clientId: String): Boolean = presence.getCoroutine(clientId = clientId).isNotEmpty()

override suspend fun enter(data: PresenceData?) {
room.ensureAttached() // CHA-PR3e, CHA-PR3d, CHA-PR3h
room.ensureAttached(logger) // CHA-PR3e, CHA-PR3d, CHA-PR3h
presence.enterClientCoroutine(room.clientId, wrapInUserCustomData(data))
}

override suspend fun update(data: PresenceData?) {
room.ensureAttached() // CHA-PR10e, CHA-PR10d, CHA-PR10h
room.ensureAttached(logger) // CHA-PR10e, CHA-PR10d, CHA-PR10h
presence.updateClientCoroutine(room.clientId, wrapInUserCustomData(data))
}

override suspend fun leave(data: PresenceData?) {
room.ensureAttached() // CHA-PR4d, CHA-PR4b, CHA-PR4c
room.ensureAttached(logger) // CHA-PR4d, CHA-PR4b, CHA-PR4c
presence.leaveClientCoroutine(room.clientId, wrapInUserCustomData(data))
}

Expand Down
52 changes: 40 additions & 12 deletions chat-android/src/main/java/com/ably/chat/Room.kt
Original file line number Diff line number Diff line change
Expand Up @@ -117,7 +117,7 @@ internal class DefaultRoom(
internal val clientId: String,
logger: Logger,
) : Room {
internal val roomLogger = logger.withContext("Room", mapOf("roomId" to roomId))
internal val logger = logger.withContext("Room", mapOf("roomId" to roomId))

/**
* RoomScope is a crucial part of the Room lifecycle. It manages sequential and atomic operations.
Expand All @@ -133,7 +133,8 @@ internal class DefaultRoom(
override val presence: Presence
get() {
if (_presence == null) { // CHA-RC2b
throw ablyException("Presence is not enabled for this room", ErrorCode.BadRequest)
logger.error("Presence access failed, not enabled in provided RoomOptions: $options")
throw clientError("Presence is not enabled for this room")
}
return _presence as Presence
}
Expand All @@ -142,7 +143,8 @@ internal class DefaultRoom(
override val reactions: RoomReactions
get() {
if (_reactions == null) { // CHA-RC2b
throw ablyException("Reactions are not enabled for this room", ErrorCode.BadRequest)
logger.error("Reactions access failed, not enabled in provided RoomOptions: $options")
throw clientError("Reactions are not enabled for this room")
}
return _reactions as RoomReactions
}
Expand All @@ -151,7 +153,8 @@ internal class DefaultRoom(
override val typing: Typing
get() {
if (_typing == null) { // CHA-RC2b
throw ablyException("Typing is not enabled for this room", ErrorCode.BadRequest)
logger.error("Typing access failed, not enabled in provided RoomOptions: $options")
throw clientError("Typing is not enabled for this room")
}
return _typing as Typing
}
Expand All @@ -160,12 +163,13 @@ internal class DefaultRoom(
override val occupancy: Occupancy
get() {
if (_occupancy == null) { // CHA-RC2b
throw ablyException("Occupancy is not enabled for this room", ErrorCode.BadRequest)
logger.error("Occupancy access failed, not enabled in provided RoomOptions: $options")
throw clientError("Occupancy is not enabled for this room")
}
return _occupancy as Occupancy
}

private val statusLifecycle = DefaultRoomLifecycle(roomLogger)
private val statusLifecycle = DefaultRoomLifecycle(this.logger)

override val status: RoomStatus
get() = statusLifecycle.status
Expand All @@ -176,7 +180,9 @@ internal class DefaultRoom(
private var lifecycleManager: RoomLifecycleManager

init {
options.validateRoomOptions() // CHA-RC2a
this.logger.debug("Initializing based on provided RoomOptions: $options")

options.validateRoomOptions(this.logger) // CHA-RC2a

// CHA-RC2e - Add contributors/features as per the order of precedence
val roomFeatures = mutableListOf<ContributesToRoomLifecycle>(messages)
Expand Down Expand Up @@ -205,7 +211,9 @@ internal class DefaultRoom(
_occupancy = occupancyContributor
}

lifecycleManager = RoomLifecycleManager(roomScope, statusLifecycle, roomFeatures, roomLogger)
lifecycleManager = RoomLifecycleManager(roomScope, statusLifecycle, roomFeatures, this.logger)

this.logger.debug("Initialized with features: ${roomFeatures.map { it.featureName }.joinWithBrackets}")
}

override fun onStatusChange(listener: RoomLifecycle.Listener): Subscription =
Expand All @@ -216,10 +224,12 @@ internal class DefaultRoom(
}

override suspend fun attach() {
logger.trace("attach();")
lifecycleManager.attach()
}

override suspend fun detach() {
logger.trace("detach();")
lifecycleManager.detach()
}

Expand All @@ -228,34 +238,49 @@ internal class DefaultRoom(
* This is an internal method and only called from Rooms interface implementation.
*/
internal suspend fun release() {
logger.trace("release();")
lifecycleManager.release()
}

/**
* Ensures that the room is attached before performing any realtime room operation.
* Accepts featureLogger as a param, to log respective operation.
* @throws roomInvalidStateException if room is not in ATTACHING/ATTACHED state.
* Spec: CHA-RL9
*/
internal suspend fun ensureAttached() {
internal suspend fun ensureAttached(featureLogger: Logger) {
featureLogger.trace("ensureAttached();")
// CHA-PR3e, CHA-PR10e, CHA-PR4d, CHA-PR6d, CHA-T2d, CHA-T4a1, CHA-T5e
when (val currentRoomStatus = statusLifecycle.status) {
RoomStatus.Attached -> return
RoomStatus.Attached -> {
featureLogger.debug("ensureAttached(); Room is already attached")
return
}
// CHA-PR3d, CHA-PR10d, CHA-PR4b, CHA-PR6c, CHA-T2c, CHA-T4a3, CHA-T5c
RoomStatus.Attaching -> { // CHA-RL9
featureLogger.debug("ensureAttached(); Room is in attaching state, waiting for attach to complete")
val attachDeferred = CompletableDeferred<Unit>()
roomScope.launch {
when (statusLifecycle.status) {
RoomStatus.Attached -> attachDeferred.complete(Unit)
RoomStatus.Attached -> {
featureLogger.debug("ensureAttached(); waiting complete, room is now ATTACHED")
attachDeferred.complete(Unit)
}
RoomStatus.Attaching -> statusLifecycle.onChangeOnce {
if (it.current == RoomStatus.Attached) {
featureLogger.debug("ensureAttached(); waiting complete, room is now ATTACHED")
attachDeferred.complete(Unit)
} else {
featureLogger.error("ensureAttached(); waiting complete, room ATTACHING failed with error: ${it.error}")
val exception =
roomInvalidStateException(roomId, statusLifecycle.status, HttpStatusCode.InternalServerError)
attachDeferred.completeExceptionally(exception)
}
}
else -> {
featureLogger.error(
"ensureAttached(); waiting complete, room ATTACHING failed with error: ${statusLifecycle.error}",
)
val exception = roomInvalidStateException(roomId, statusLifecycle.status, HttpStatusCode.InternalServerError)
attachDeferred.completeExceptionally(exception)
}
Expand All @@ -265,7 +290,10 @@ internal class DefaultRoom(
return
}
// CHA-PR3h, CHA-PR10h, CHA-PR4c, CHA-PR6h, CHA-T2g, CHA-T4a4, CHA-T5d
else -> throw roomInvalidStateException(roomId, currentRoomStatus, HttpStatusCode.BadRequest)
else -> {
featureLogger.error("ensureAttached(); Room is in invalid state: $currentRoomStatus, error: ${statusLifecycle.error}")
throw roomInvalidStateException(roomId, currentRoomStatus, HttpStatusCode.BadRequest)
}
}
}
}
Loading
Loading