Skip to content

Commit

Permalink
Merge pull request #84 from ably/feature/room-logging
Browse files Browse the repository at this point in the history 
feat: Implement logging for Room, RoomLifecycleManager
  • Loading branch information
@sacOO7
sacOO7 authored Dec 12, 2024
2 parents f24dc54 + 037d607 commit 1f0de95
Show file tree
Hide file tree
Showing 16 changed files with 230 additions and 133 deletions.
4 changes: 2 additions & 2 deletions chat-android/src/main/java/com/ably/chat/Logger.kt
View file
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
View file
Original file line number Diff line number Diff line change
Expand Up @@ -205,13 +205,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
View file
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
View file
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
View file
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

0 comments on commit 1f0de95

Please sign in to comment.