diff --git a/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/CDNClientPool.kt b/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/CDNClientPool.kt index ce7ec2d5..8e5c5f76 100644 --- a/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/CDNClientPool.kt +++ b/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/CDNClientPool.kt @@ -29,7 +29,7 @@ class CDNClientPool( private val steamSession: Steam3Session, private val appId: Int, private val scope: CoroutineScope, - debug: Boolean = false, + private val debug: Boolean = false, ) : AutoCloseable { private var logger: Logger? = null @@ -49,13 +49,11 @@ class CDNClientPool( init { cdnClient = Client(steamSession.steamClient) - if (debug) { - logger = LogManager.getLogger(CDNClientPool::class.java) - } + logger = LogManager.getLogger(CDNClientPool::class.java) } override fun close() { - logger?.debug("Closing...") + if (debug) logger?.debug("Closing...") servers.set(emptyList()) @@ -89,7 +87,7 @@ class CDNClientPool( nextServer.set(0) // servers.joinToString(separator = "\n", prefix = "Servers:\n") { "- $it" } - logger?.debug("Found ${weightedCdnServers.size} Servers") + if (debug) logger?.debug("Found ${weightedCdnServers.size} Servers") if (weightedCdnServers.isEmpty()) { throw Exception("Failed to retrieve any download servers.") @@ -102,7 +100,7 @@ class CDNClientPool( val index = nextServer.getAndIncrement() val server = servers[index % servers.size] - logger?.debug("Getting connection $server") + if (debug) logger?.debug("Getting connection $server") return server } @@ -113,7 +111,7 @@ class CDNClientPool( return } - logger?.debug("Returning connection: $server") + if (debug) logger?.debug("Returning connection: $server") // (SK) nothing to do, maybe remove from ContentServerPenalty? } @@ -124,7 +122,7 @@ class CDNClientPool( return } - logger?.debug("Returning broken connection: $server") + if (debug) logger?.debug("Returning broken connection: $server") val servers = servers.get() val currentIndex = nextServer.get() diff --git a/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/DepotDownloader.kt b/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/DepotDownloader.kt index 539717d0..547a3e3b 100644 --- a/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/DepotDownloader.kt +++ b/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/DepotDownloader.kt @@ -49,6 +49,7 @@ import kotlinx.coroutines.awaitAll import kotlinx.coroutines.cancel import kotlinx.coroutines.channels.Channel import kotlinx.coroutines.coroutineScope +import kotlinx.coroutines.delay import kotlinx.coroutines.ensureActive import kotlinx.coroutines.flow.MutableSharedFlow import kotlinx.coroutines.flow.collect @@ -232,13 +233,12 @@ class DepotDownloader @JvmOverloads constructor( // endregion init { - if (debug) { - logger = LogManager.getLogger(DepotDownloader::class.java) - } + logger = LogManager.getLogger(DepotDownloader::class.java) steam3 = Steam3Session(steamClient, debug) - logger?.debug("DepotDownloader launched with ${licenses.size} for account") + if (debug) logger?.debug("DepotDownloader launched with ${licenses.size} for account") + licenses.forEach { license -> if (license.accessToken.toULong() > 0UL) { steam3!!.packageTokens[license.packageID] = license.accessToken @@ -398,14 +398,14 @@ class DepotDownloader @JvmOverloads constructor( filesystem.createDirectories(fileStagingPath.parent!!) httpClient.getClient().use { client -> - logger?.debug("Starting download of $fileName...") + if (debug) logger?.debug("Starting download of $fileName...") val response = client.get(url) val channel = response.bodyAsChannel() val totalBytes = response.headers[HttpHeaders.ContentLength]?.toLongOrNull() - logger?.debug("File size: ${totalBytes?.let { Util.formatBytes(it) } ?: "Unknown"}") + if (debug) logger?.debug("File size: ${totalBytes?.let { Util.formatBytes(it) } ?: "Unknown"}") filesystem.sink(fileStagingPath).buffer().use { sink -> val buffer = Buffer() @@ -423,17 +423,17 @@ class DepotDownloader @JvmOverloads constructor( } } - logger?.debug("Download completed.") + if (debug) logger?.debug("Download completed.") } if (filesystem.exists(fileFinalPath)) { - logger?.debug("Deleting $fileFinalPath") + if (debug) logger?.debug("Deleting $fileFinalPath") filesystem.delete(fileFinalPath) } try { filesystem.atomicMove(fileStagingPath, fileFinalPath) - logger?.debug("File '$fileStagingPath' moved to final location: $fileFinalPath") + if (debug) logger?.debug("File '$fileStagingPath' moved to final location: $fileFinalPath") } catch (e: IOException) { logger?.error("Failed to move files", e) throw e @@ -470,7 +470,7 @@ class DepotDownloader @JvmOverloads constructor( if (!accountHasAccess(appId, appId)) { if (steamUser.steamID!!.accountType != EAccountType.AnonUser && steam3!!.requestFreeAppLicense(appId)) { - logger?.debug("Obtained FreeOnDemand license for app $appId") + if (debug) logger?.debug("Obtained FreeOnDemand license for app $appId") // Fetch app info again in case we didn't get it fully without a license. steam3!!.requestAppInfo(appId, true) @@ -494,7 +494,7 @@ class DepotDownloader @JvmOverloads constructor( depotIdsFound.addAll(depotIdsExpected) } else { - logger?.debug("Using app branch: $branch") + if (debug) logger?.debug("Using app branch: $branch") depots?.children?.forEach { depotSection -> if (depotSection.children.isEmpty()) { @@ -946,10 +946,12 @@ class DepotDownloader @JvmOverloads constructor( } } - logger?.debug( - "Total downloaded: ${downloadCounter.totalBytesCompressed} bytes " + - "(${downloadCounter.totalBytesUncompressed} bytes uncompressed) from ${depots.size} depots" - ) + if (debug) { + logger?.debug( + "Total downloaded: ${downloadCounter.totalBytesCompressed} bytes " + + "(${downloadCounter.totalBytesUncompressed} bytes uncompressed) from ${depots.size} depots" + ) + } } private suspend fun processDepotManifestAndFiles( @@ -958,7 +960,7 @@ class DepotDownloader @JvmOverloads constructor( ): DepotFilesData? = withContext(Dispatchers.IO) { val depotCounter = DepotDownloadCounter() - logger?.debug("Processing depot ${depot.depotId}") + if (debug) logger?.debug("Processing depot ${depot.depotId}") var oldManifest: DepotManifest? = null @@ -983,14 +985,14 @@ class DepotDownloader @JvmOverloads constructor( if (lastManifestId == depot.manifestId && oldManifest != null) { newManifest = oldManifest - logger?.debug("Already have manifest ${depot.manifestId} for depot ${depot.depotId}.") + if (debug) logger?.debug("Already have manifest ${depot.manifestId} for depot ${depot.depotId}.") } else { newManifest = Util.loadManifestFromFile(configDir, depot.depotId, depot.manifestId, true) if (newManifest != null) { - logger?.debug("Already have manifest ${depot.manifestId} for depot ${depot.depotId}.") + if (debug) logger?.debug("Already have manifest ${depot.manifestId} for depot ${depot.depotId}.") } else { - logger?.debug("Downloading depot ${depot.depotId} manifest") + if (debug) logger?.debug("Downloading depot ${depot.depotId} manifest") notifyListeners { it.onStatusUpdate("Downloading manifest for depot ${depot.depotId}") } var manifestRequestCode: ULong = 0U @@ -1040,7 +1042,7 @@ class DepotDownloader @JvmOverloads constructor( } } - logger?.debug("Downloading manifest ${depot.manifestId} from $connection with ${cdnClientPool!!.proxyServer ?: "no proxy"}") + if (debug) logger?.debug("Downloading manifest ${depot.manifestId} from $connection with ${cdnClientPool!!.proxyServer ?: "no proxy"}") newManifest = cdnClientPool!!.cdnClient!!.downloadManifest( depotId = depot.depotId, @@ -1100,7 +1102,7 @@ class DepotDownloader @JvmOverloads constructor( } } - logger?.debug("Manifest ${depot.manifestId} (${newManifest.creationTime})") + if (debug) logger?.debug("Manifest ${depot.manifestId} (${newManifest.creationTime})") if (config.downloadManifestOnly) { Util.dumpManifestToTextFile(depot, newManifest) @@ -1162,7 +1164,7 @@ class DepotDownloader @JvmOverloads constructor( val depot = depotFilesData.depotDownloadInfo val depotCounter = depotFilesData.depotCounter - logger?.debug("Downloading depot ${depot.depotId}") + if (debug) logger?.debug("Downloading depot ${depot.depotId}") val files = depotFilesData.filteredFiles.filter { !it.flags.contains(EDepotFileFlag.Directory) } @@ -1185,14 +1187,14 @@ class DepotDownloader @JvmOverloads constructor( } } finally { if (isLastDepot) { - logger?.debug("Waiting for ${pendingChunks.get()} pending chunks to complete for depot ${depot.depotId}") + if (debug) logger?.debug("Waiting for ${pendingChunks.get()} pending chunks to complete for depot ${depot.depotId}") // Wait for all pending chunks to complete processing while (pendingChunks.get() > 0) { - kotlinx.coroutines.delay(100) + delay(100) } - logger?.debug("All chunks completed, canceling processing job for depot ${depot.depotId}") + if (debug) logger?.debug("All chunks completed, canceling processing job for depot ${depot.depotId}") // Cancel the continuous flow job since no more chunks will be added chunkProcessingJob?.cancel() @@ -1225,7 +1227,7 @@ class DepotDownloader @JvmOverloads constructor( } filesystem.delete(fileFinalPath) - logger?.debug("Deleted $fileFinalPath") + if (debug) logger?.debug("Deleted $fileFinalPath") } } @@ -1241,7 +1243,7 @@ class DepotDownloader @JvmOverloads constructor( ) } - logger?.debug("Depot ${depot.depotId} - Downloaded ${depotCounter.depotBytesCompressed} bytes (${depotCounter.depotBytesUncompressed} bytes uncompressed)") + if (debug) logger?.debug("Depot ${depot.depotId} - Downloaded ${depotCounter.depotBytesCompressed} bytes (${depotCounter.depotBytesUncompressed} bytes uncompressed)") if (isLastDepot) { finishDepotDownload(mainAppId) @@ -1276,7 +1278,8 @@ class DepotDownloader @JvmOverloads constructor( var neededChunks: MutableList? = null val fileDidExist = filesystem.exists(fileFinalPath) if (!fileDidExist) { - logger?.debug("Pre-allocating: $fileFinalPath") + if (debug) logger?.debug("Pre-allocating: $fileFinalPath") + notifyListeners { it.onStatusUpdate("Allocating file: ${file.fileName}") } // create new file. need all chunks @@ -1299,7 +1302,7 @@ class DepotDownloader @JvmOverloads constructor( if (config.verifyAll || !hashMatches) { // we have a version of this file, but it doesn't fully match what we want if (config.verifyAll) { - logger?.debug("Validating: $fileFinalPath") + if (debug) logger?.debug("Validating: $fileFinalPath") } val matchingChunks = arrayListOf() @@ -1396,7 +1399,8 @@ class DepotDownloader @JvmOverloads constructor( } filesystem.openReadWrite(fileFinalPath).use { handle -> - logger?.debug("Validating $fileFinalPath") + if (debug) logger?.debug("Validating $fileFinalPath") + notifyListeners { it.onStatusUpdate("Validating: ${file.fileName}") } neededChunks = Util.validateSteam3FileChecksums( @@ -1412,7 +1416,8 @@ class DepotDownloader @JvmOverloads constructor( val percentage = (depotDownloadCounter.sizeDownloaded / depotDownloadCounter.completeDownloadSize.toFloat()) * 100.0f - logger?.debug("%.2f%% %s".format(percentage, fileFinalPath)) + + if (debug) logger?.debug("%.2f%% %s".format(percentage, fileFinalPath)) } synchronized(downloadCounter) { @@ -1503,7 +1508,7 @@ class DepotDownloader @JvmOverloads constructor( } } - logger?.debug("Downloading chunk $chunkID from $connection with ${cdnClientPool!!.proxyServer ?: "no proxy"}") + if (debug) logger?.debug("Downloading chunk $chunkID from $connection with ${cdnClientPool!!.proxyServer ?: "no proxy"}") downloaded = cdnClientPool!!.cdnClient!!.downloadDepotChunk( depotId = depot.depotId, @@ -1700,13 +1705,13 @@ class DepotDownloader @JvmOverloads constructor( when (item) { is PubFileItem -> { - logger?.debug("Downloading PUB File for ${item.appId}") + if (debug) logger?.debug("Downloading PUB File for ${item.appId}") notifyListeners { it.onDownloadStarted(item) } downloadPubFile(item.appId, item.pubFile) } is UgcItem -> { - logger?.debug("Downloading UGC File for ${item.appId}") + if (debug) logger?.debug("Downloading UGC File for ${item.appId}") notifyListeners { it.onDownloadStarted(item) } downloadUGC(item.appId, item.ugcId) } @@ -1758,8 +1763,10 @@ class DepotDownloader @JvmOverloads constructor( depotManifestIds.addAll(depotIdList.map { it to INVALID_MANIFEST_ID }) } - logger?.debug("Downloading App for ${item.appId}") + if (debug) logger?.debug("Downloading App for ${item.appId}") + notifyListeners { it.onDownloadStarted(item) } + downloadApp( appId = item.appId, depotManifestIds = depotManifestIds, @@ -1863,7 +1870,7 @@ class DepotDownloader @JvmOverloads constructor( ) } - logger?.debug("%.2f%% %s".format(depotPercentage, fileFinalPath)) + if (debug) logger?.debug("%.2f%% %s".format(depotPercentage, fileFinalPath)) } else { // Update counters and notify on chunk completion val sizeDownloaded: Long diff --git a/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/Steam3Session.kt b/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/Steam3Session.kt index de86be16..2c114a70 100644 --- a/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/Steam3Session.kt +++ b/javasteam-depotdownloader/src/main/kotlin/in/dragonbra/javasteam/depotdownloader/Steam3Session.kt @@ -41,7 +41,7 @@ import java.util.concurrent.ConcurrentHashMap */ class Steam3Session( internal val steamClient: SteamClient, - debug: Boolean, + private val debug: Boolean, ) : Closeable { private var logger: Logger? = null @@ -67,9 +67,7 @@ class Steam3Session( internal data class Optional(val value: T?) init { - if (debug) { - logger = LogManager.getLogger(Steam3Session::class.java) - } + logger = LogManager.getLogger(Steam3Session::class.java) unifiedMessages = requireNotNull(steamClient.getHandler()) steamApps = requireNotNull(steamClient.getHandler()) @@ -80,7 +78,7 @@ class Steam3Session( } override fun close() { - logger?.debug("Closing...") + if (debug) logger?.debug("Closing...") unifiedMessages = null steamUser = null @@ -107,7 +105,7 @@ class Steam3Session( suspend fun requestAppInfo(appId: Int, bForce: Boolean = false) { if ((appInfo.containsKey(appId) && !bForce) || isAborted) { - logger?.debug("requestAppInfo already has $appId or is aborting") + if (debug) logger?.debug("requestAppInfo already has $appId or is aborting") return } @@ -129,14 +127,16 @@ class Steam3Session( val appInfoMultiple = steamApps!!.picsGetProductInfo(request).await() - logger?.debug( - "requestAppInfo($appId, $bForce) with \n" + - "${appTokens.appTokens.size} appTokens, \n" + - "${appTokens.appTokensDenied.size} appTokensDenied, \n" + - "${appTokens.packageTokens.size} packageTokens, and \n" + - "${appTokens.packageTokensDenied} packageTokensDenied. \n" + - "picsGetProductInfo result size: ${appInfoMultiple.results.size}" - ) + if (debug) { + logger?.debug( + "requestAppInfo($appId, $bForce) with \n" + + "${appTokens.appTokens.size} appTokens, \n" + + "${appTokens.appTokensDenied.size} appTokensDenied, \n" + + "${appTokens.packageTokens.size} packageTokens, and \n" + + "${appTokens.packageTokensDenied} packageTokensDenied. \n" + + "picsGetProductInfo result size: ${appInfoMultiple.results.size}" + ) + } appInfoMultiple.results.forEach { appInfo -> appInfo.apps.forEach { appValue -> @@ -153,7 +153,7 @@ class Steam3Session( private val packageInfoMutex = Mutex() suspend fun requestPackageInfo(packageIds: List) { packageInfoMutex.withLock { - logger?.debug("requestPackageInfo() invoked with ${packageIds.size} packageIds") + if (debug) logger?.debug("requestPackageInfo() invoked with ${packageIds.size} packageIds") // I have a silly race condition??? val packages = packageIds.filter { !packageInfo.containsKey(it) } @@ -176,7 +176,7 @@ class Steam3Session( val packageInfoMultiple = steamApps!!.picsGetProductInfo(emptyList(), packageRequests).await() - logger?.debug("requestPackageInfo() picsGetProductInfo result size: ${packageInfoMultiple.results.size} ") + if (debug) logger?.debug("requestPackageInfo() picsGetProductInfo result size: ${packageInfoMultiple.results.size} ") packageInfoMultiple.results.forEach { pkgInfo -> pkgInfo.packages.forEach { pkgValue -> @@ -194,7 +194,7 @@ class Steam3Session( try { val resultInfo = steamApps!!.requestFreeLicense(appId).await() - logger?.debug("requestFreeAppLicense($appId) has result ${resultInfo.result}") + if (debug) logger?.debug("requestFreeAppLicense($appId) has result ${resultInfo.result}") return resultInfo.grantedApps.contains(appId) } catch (e: Exception) { @@ -205,16 +205,18 @@ class Steam3Session( suspend fun requestDepotKey(depotId: Int, appId: Int = 0) { if (depotKeys.containsKey(depotId) || isAborted) { - logger?.debug("requestDepotKey already has $depotId or is aborting.") + if (debug) logger?.debug("requestDepotKey already has $depotId or is aborting.") return } val depotKey = steamApps!!.getDepotDecryptionKey(depotId, appId).await() - logger?.debug( - "requestDepotKey($depotId, $appId) " + - "Got depot key for ${depotKey.depotID} result: ${depotKey.result}" - ) + if (debug) { + logger?.debug( + "requestDepotKey($depotId, $appId) " + + "Got depot key for ${depotKey.depotID} result: ${depotKey.result}" + ) + } if (depotKey.result != EResult.OK) { logger?.error("requestDepotKey result was ${depotKey.result}") @@ -248,16 +250,18 @@ class Steam3Session( logger?.error("No manifest request code was returned for depot $depotId from app $appId, manifest $manifestId") if (steamClient.isDisconnected) { - logger?.debug("Suggestion: Try logging in with a username as old manifests may not be available for anonymous accounts.") + logger?.error("Suggestion: Try logging in with a username as old manifests may not be available for anonymous accounts.") } } else { - logger?.debug("Got manifest request code for depot $depotId from app $appId, manifest $manifestId, result: $requestCode") + if (debug) logger?.debug("Got manifest request code for depot $depotId from app $appId, manifest $manifestId, result: $requestCode") } - logger?.debug( - "getDepotManifestRequestCode($depotId, $appId, $manifestId, $branch) " + - "got request code $requestCode" - ) + if (debug) { + logger?.debug( + "getDepotManifestRequestCode($depotId, $appId, $manifestId, $branch) " + + "got request code $requestCode" + ) + } return@withContext requestCode } @@ -266,22 +270,22 @@ class Steam3Session( val cdnKey = depotId to server.host!! if (cdnAuthTokens.containsKey(cdnKey)) { - logger?.debug("requestCDNAuthToken already has $cdnKey") + if (debug) logger?.debug("requestCDNAuthToken already has $cdnKey") return@withContext } val completion = CompletableDeferred() if (isAborted || cdnAuthTokens.putIfAbsent(cdnKey, completion) != null) { - logger?.debug("requestCDNAuthToken is aborting or unable to map $cdnKey") + if (debug) logger?.debug("requestCDNAuthToken is aborting or unable to map $cdnKey") return@withContext } - logger?.debug("Requesting CDN auth token for ${server.host}") + if (debug) logger?.debug("Requesting CDN auth token for ${server.host}") val cdnAuth = steamContent!!.getCDNAuthToken(appId, depotId, server.host!!, this).await() - logger?.debug("Got CDN auth token for ${server.host} result: ${cdnAuth.result} (expires ${cdnAuth.expiration})") + if (debug) logger?.debug("Got CDN auth token for ${server.host} result: ${cdnAuth.result} (expires ${cdnAuth.expiration})") if (cdnAuth.result != EResult.OK) { logger?.error("requestCDNAuthToken result was ${cdnAuth.result}") @@ -294,10 +298,12 @@ class Steam3Session( suspend fun checkAppBetaPassword(appId: Int, password: String) { val appPassword = steamApps!!.checkAppBetaPassword(appId, password).await() - logger?.debug( - "checkAppBetaPassword($appId, )," + - "retrieved ${appPassword.betaPasswords.size} beta keys with result: ${appPassword.result}" - ) + if (debug) { + logger?.debug( + "checkAppBetaPassword($appId, )," + + "retrieved ${appPassword.betaPasswords.size} beta keys with result: ${appPassword.result}" + ) + } appPassword.betaPasswords.forEach { entry -> this.appBetaPasswords[entry.key] = entry.value @@ -313,7 +319,7 @@ class Steam3Session( val privateBeta = steamApps!!.picsGetPrivateBeta(appId, accessToken, branch, branchPassword).await() - logger?.debug("getPrivateBetaDepotSection($appId, $branch) result: ${privateBeta.result}") + if (debug) logger?.debug("getPrivateBetaDepotSection($appId, $branch) result: ${privateBeta.result}") return privateBeta.depotSection } @@ -332,7 +338,7 @@ class Steam3Session( val details = steamPublishedFile!!.getDetails(pubFileRequest).await() - logger?.debug("requestUGCDetails($appId, $pubFile) result: ${details.result}") + if (debug) logger?.debug("requestUGCDetails($appId, $pubFile) result: ${details.result}") if (details.result == EResult.OK) { return details.body.publishedfiledetailsBuilderList.firstOrNull()?.build() @@ -344,7 +350,7 @@ class Steam3Session( suspend fun getUGCDetails(ugcHandle: UGCHandle): UGCDetailsCallback? { val callback = steamCloud!!.requestUGCDetails(ugcHandle).await() - logger?.debug("requestUGCDetails($ugcHandle) result: ${callback.result}") + if (debug) logger?.debug("requestUGCDetails($ugcHandle) result: ${callback.result}") if (callback.result == EResult.OK) { return callback