Skip to content

Re-Add debug logging for ds listing #8251

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.

Sign up for GitHub

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

Merged
merged 14 commits into from
Dec 2, 2024
Merged

Re-Add debug logging for ds listing #8251

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
14 commits
Select commit Hold shift + click to select a range
f0b1b2f
add debug logging for dataset list route
Nov 28, 2024
82690ac
add extensive logging to listGrouped method of DatasetController
Nov 28, 2024
ed69e48
Merge branch 'master' into add-debug-logging-for-ds-listing
fm3 Nov 28, 2024
4c75c97
dont log full objects
Nov 28, 2024
fe47da7
Merge branch 'add-debug-logging-for-ds-listing' of github.com:scalabl…
Nov 28, 2024
b6e432b
Merge branch 'master' into add-debug-logging-for-ds-listing
fm3 Nov 28, 2024
6295857
restore logging full object except for user objects
Nov 28, 2024
2179355
Merge branch 'add-debug-logging-for-ds-listing' of github.com:scalabl…
Nov 28, 2024
d7bebd7
Merge branch 'master' of github.com:scalableminds/webknossos into add…
Nov 29, 2024
08678ab
re add extensive logging for debugging
Nov 29, 2024
5723c74
Merge branches 'add-debug-logging-for-ds-listing' and 'master' of git…
Dec 2, 2024
932c473
re add global access context to finding organizations in DSController…
Dec 2, 2024
d19bb41
Merge branch 'master' into add-debug-logging-for-ds-listing
fm3 Dec 2, 2024
abab9a8
Merge branch 'master' into add-debug-logging-for-ds-listing
MichaelBuessemeyer Dec 2, 2024
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
105 changes: 63 additions & 42 deletions app/controllers/DatasetController.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -176,70 +176,91 @@ class DatasetController @Inject()(userService: UserService,
// Change output format to return only a compact list with essential information on the datasets
compact: Option[Boolean]
): Action[AnyContent] = sil.UserAwareAction.async { implicit request =>
for {
folderIdValidated <- Fox.runOptional(folderId)(ObjectId.fromString)
uploaderIdValidated <- Fox.runOptional(uploaderId)(ObjectId.fromString)
organizationIdOpt = if (onlyMyOrganization.getOrElse(false))
request.identity.map(_._organization)
else
organizationId
js <- if (compact.getOrElse(false)) {
for {
datasetInfos <- datasetDAO.findAllCompactWithSearch(
isActive,
isUnreported,
organizationIdOpt,
folderIdValidated,
uploaderIdValidated,
searchQuery,
request.identity.map(_._id),
recursive.getOrElse(false),
limitOpt = limit
)
} yield Json.toJson(datasetInfos)
} else {
for {
datasets <- datasetDAO.findAllWithSearch(isActive,
isUnreported,
organizationIdOpt,
folderIdValidated,
uploaderIdValidated,
searchQuery,
recursive.getOrElse(false),
limit) ?~> "dataset.list.failed"
js <- listGrouped(datasets, request.identity) ?~> "dataset.list.failed"
} yield Json.toJson(js)
}
_ = Fox.runOptional(request.identity)(user => userDAO.updateLastActivity(user._id))
} yield addRemoteOriginHeaders(Ok(js))
log() {
for {
folderIdValidated <- Fox.runOptional(folderId)(ObjectId.fromString)
uploaderIdValidated <- Fox.runOptional(uploaderId)(ObjectId.fromString)
organizationIdOpt = if (onlyMyOrganization.getOrElse(false))
request.identity.map(_._organization)
else
organizationId
js <- if (compact.getOrElse(false)) {
for {
datasetInfos <- datasetDAO.findAllCompactWithSearch(
isActive,
isUnreported,
organizationIdOpt,
folderIdValidated,
uploaderIdValidated,
searchQuery,
request.identity.map(_._id),
recursive.getOrElse(false),
limitOpt = limit
)
} yield Json.toJson(datasetInfos)
} else {
for {
_ <- Fox.successful(())
_ = logger.info(
s"Requesting listing datasets with isActive '$isActive', isUnreported '$isUnreported', organizationId '$organizationIdOpt', folderId '$folderIdValidated', uploaderId '$uploaderIdValidated', searchQuery '$searchQuery', recursive '$recursive', limit '$limit'")
Comment on lines +204 to +205
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🛠️ Refactor suggestion

Consider adjusting log levels and format for production use

The logging statements provide valuable debugging information but consider:

  1. Moving detailed parameter logging to DEBUG level
  2. Using structured logging format for better parsing
  3. Avoiding logging sensitive IDs in production
-            _ = logger.info(
-              s"Requesting listing datasets with isActive '$isActive', isUnreported '$isUnreported', organizationId '$organizationIdOpt', folderId '$folderIdValidated', uploaderId '$uploaderIdValidated', searchQuery '$searchQuery', recursive '$recursive', limit '$limit'")
+            _ = logger.debug("Requesting dataset listing",
+              "isActive" -> isActive,
+              "isUnreported" -> isUnreported,
+              "hasOrganizationId" -> organizationIdOpt.isDefined,
+              "hasFolderId" -> folderIdValidated.isDefined,
+              "hasUploaderId" -> uploaderIdValidated.isDefined,
+              "hasSearchQuery" -> searchQuery.isDefined,
+              "recursive" -> recursive,
+              "limit" -> limit)

-            _ = logger.info(s"Found ${datasets.size} datasets successfully")
+            _ = logger.debug("Dataset listing completed", "count" -> datasets.size)

Also applies to: 214-214

datasets <- datasetDAO.findAllWithSearch(isActive,
isUnreported,
organizationIdOpt,
folderIdValidated,
uploaderIdValidated,
searchQuery,
recursive.getOrElse(false),
limit) ?~> "dataset.list.failed" ?~> "Dataset listing failed"
_ = logger.info(s"Found ${datasets.size} datasets successfully")
js <- listGrouped(datasets, request.identity) ?~> "dataset.list.failed" ?~> "Grouping datasets failed"
} yield Json.toJson(js)
}
_ = Fox.runOptional(request.identity)(user => userDAO.updateLastActivity(user._id))
} yield addRemoteOriginHeaders(Ok(js))
}
}

private def listGrouped(datasets: List[Dataset], requestingUser: Option[User])(
implicit ctx: DBAccessContext,
m: MessagesProvider): Fox[List[JsObject]] =
for {
_ <- Fox.successful(())
_ = logger.info(s"datasets: $datasets, requestingUser: ${requestingUser.map(_._id)}")
Comment on lines +227 to +228
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Potential issue

Avoid logging sensitive information

The logging statements include sensitive information like user IDs and dataset details. Consider:

  1. Masking or truncating sensitive IDs
  2. Reducing the verbosity of dataset information
  3. Moving detailed logging to DEBUG level
-      _ = logger.info(s"datasets: $datasets, requestingUser: ${requestingUser.map(_._id)}")
+      _ = logger.debug("Processing datasets",
+        "datasetCount" -> datasets.size,
+        "hasRequestingUser" -> requestingUser.isDefined)

-      _ = logger.info(s"byOrgaTuple orga: ${byOrgaTuple._1}, datasets: ${byOrgaTuple._2}")
+      _ = logger.debug("Processing organization datasets",
+        "organizationId" -> byOrgaTuple._1,
+        "datasetCount" -> byOrgaTuple._2.size)

-              logger.info(s"datastore: ${byDataStoreTuple._1}, datasets: ${byDataStoreTuple._2}")
+              logger.debug("Processing datastore datasets",
+                "datastoreName" -> byDataStoreTuple._1,
+                "datasetCount" -> byDataStoreTuple._2.size)

Also applies to: 238-239, 244-244

requestingUserTeamManagerMemberships <- Fox.runOptional(requestingUser)(user =>
userService.teamManagerMembershipsFor(user._id))
userService
.teamManagerMembershipsFor(user._id)) ?~> s"Could not find team manager memberships for user ${requestingUser
.map(_._id)}"
_ = logger.info(
s"requestingUserTeamManagerMemberships: ${requestingUserTeamManagerMemberships.map(_.map(_.toString))}")
groupedByOrga = datasets.groupBy(_._organization).toList
js <- Fox.serialCombined(groupedByOrga) { byOrgaTuple: (String, List[Dataset]) =>
for {
organization <- organizationDAO.findOne(byOrgaTuple._1)(GlobalAccessContext)
_ <- Fox.successful(())
_ = logger.info(s"byOrgaTuple orga: ${byOrgaTuple._1}, datasets: ${byOrgaTuple._2}")
organization <- organizationDAO.findOne(byOrgaTuple._1)(GlobalAccessContext) ?~> s"Could not find organization ${byOrgaTuple._1}"
groupedByDataStore = byOrgaTuple._2.groupBy(_._dataStore).toList
_ <- Fox.serialCombined(groupedByDataStore) { byDataStoreTuple: (String, List[Dataset]) =>
{
logger.info(s"datastore: ${byDataStoreTuple._1}, datasets: ${byDataStoreTuple._2}")
Fox.successful(())
}
}
result <- Fox.serialCombined(groupedByDataStore) { byDataStoreTuple: (String, List[Dataset]) =>
for {
dataStore <- dataStoreDAO.findOneByName(byDataStoreTuple._1.trim)(GlobalAccessContext)
dataStore <- dataStoreDAO.findOneByName(byDataStoreTuple._1.trim)(GlobalAccessContext) ?~>
s"Could not find data store ${byDataStoreTuple._1}"
resultByDataStore: Seq[JsObject] <- Fox.serialCombined(byDataStoreTuple._2) { d =>
datasetService.publicWrites(
d,
requestingUser,
Some(organization),
Some(dataStore),
requestingUserTeamManagerMemberships) ?~> Messages("dataset.list.writesFailed", d.name)
}
} ?~> "Could not find public writes for datasets"
} yield resultByDataStore
}
} ?~> s"Could not group by datastore for datasets ${byOrgaTuple._2.map(_._id)}"
} yield result.flatten
}
} ?~> s"Could not group by organization for datasets ${datasets.map(_._id)}"
} yield js.flatten

def accessList(datasetId: String): Action[AnyContent] = sil.SecuredAction.async { implicit request =>
Expand Down
14 changes: 9 additions & 5 deletions app/models/dataset/Dataset.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -115,12 +115,14 @@ class DatasetDAO @Inject()(sqlClient: SqlClient, datasetLayerDAO: DatasetLayerDA

protected def parse(r: DatasetsRow): Fox[Dataset] =
for {
voxelSize <- parseVoxelSizeOpt(r.voxelsizefactor, r.voxelsizeunit)
voxelSize <- parseVoxelSizeOpt(r.voxelsizefactor, r.voxelsizeunit) ?~> "could not parse dataset voxel size"
defaultViewConfigurationOpt <- Fox.runOptional(r.defaultviewconfiguration)(
JsonHelper.parseAndValidateJson[DatasetViewConfiguration](_))
JsonHelper
.parseAndValidateJson[DatasetViewConfiguration](_)) ?~> "could not parse dataset default view configuration"
adminViewConfigurationOpt <- Fox.runOptional(r.adminviewconfiguration)(
JsonHelper.parseAndValidateJson[DatasetViewConfiguration](_))
metadata <- JsonHelper.parseAndValidateJson[JsArray](r.metadata)
JsonHelper
.parseAndValidateJson[DatasetViewConfiguration](_)) ?~> "could not parse dataset admin view configuration"
metadata <- JsonHelper.parseAndValidateJson[JsArray](r.metadata) ?~> "could not parse dataset metadata"
} yield {
Dataset(
ObjectId(r._Id),
Expand Down Expand Up @@ -218,9 +220,11 @@ class DatasetDAO @Inject()(sqlClient: SqlClient, datasetLayerDAO: DatasetLayerDA
includeSubfolders,
None,
None)
_ = logger.info(s"Requesting datasets with selection predicates '$selectionPredicates'")
limitQuery = limitOpt.map(l => q"LIMIT $l").getOrElse(q"")
_ = logger.info("Requesting datasets with query")
r <- run(q"SELECT $columns FROM $existingCollectionName WHERE $selectionPredicates $limitQuery".as[DatasetsRow])
parsed <- parseAll(r)
parsed <- parseAll(r) ?~> "Parsing datasets failed"
} yield parsed

def findAllCompactWithSearch(isActiveOpt: Option[Boolean] = None,
Expand Down
22 changes: 11 additions & 11 deletions app/models/dataset/DatasetService.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -349,19 +349,19 @@ class DatasetService @Inject()(organizationDAO: OrganizationDAO,
organizationDAO.findOne(dataset._organization) ?~> "organization.notFound"
}
dataStore <- Fox.fillOption(dataStore) {
dataStoreFor(dataset)
dataStoreFor(dataset) ?~> s"fetching data store failed for dataset ${dataset._id}"
}
teams <- teamService.allowedTeamsForDataset(dataset, cumulative = false, requestingUserOpt) ?~> "dataset.list.fetchAllowedTeamsFailed"
teamsJs <- Fox.serialCombined(teams)(t => teamService.publicWrites(t, Some(organization))) ?~> "dataset.list.teamWritesFailed"
teamsCumulative <- teamService.allowedTeamsForDataset(dataset, cumulative = true, requestingUserOpt) ?~> "dataset.list.fetchAllowedTeamsFailed"
teamsCumulativeJs <- Fox.serialCombined(teamsCumulative)(t => teamService.publicWrites(t, Some(organization))) ?~> "dataset.list.teamWritesFailed"
logoUrl <- logoUrlFor(dataset, Some(organization)) ?~> "dataset.list.fetchLogoUrlFailed"
isEditable <- isEditableBy(dataset, requestingUserOpt, requestingUserTeamManagerMemberships) ?~> "dataset.list.isEditableCheckFailed"
lastUsedByUser <- lastUsedTimeFor(dataset._id, requestingUserOpt) ?~> "dataset.list.fetchLastUsedTimeFailed"
dataStoreJs <- dataStoreService.publicWrites(dataStore) ?~> "dataset.list.dataStoreWritesFailed"
dataSource <- dataSourceFor(dataset, Some(organization)) ?~> "dataset.list.fetchDataSourceFailed"
teams <- teamService.allowedTeamsForDataset(dataset, cumulative = false, requestingUserOpt) ?~> "dataset.list.fetchAllowedTeamsFailed" ?~> s"for dataset ${dataset._id}"
teamsJs <- Fox.serialCombined(teams)(t => teamService.publicWrites(t, Some(organization))) ?~> "dataset.list.teamWritesFailed" ?~> s"for dataset ${dataset._id}"
teamsCumulative <- teamService.allowedTeamsForDataset(dataset, cumulative = true, requestingUserOpt) ?~> "dataset.list.fetchAllowedTeamsFailed" ?~> s"for dataset ${dataset._id}"
teamsCumulativeJs <- Fox.serialCombined(teamsCumulative)(t => teamService.publicWrites(t, Some(organization))) ?~> "dataset.list.teamWritesFailed" ?~> s"for dataset ${dataset._id}"
logoUrl <- logoUrlFor(dataset, Some(organization)) ?~> "dataset.list.fetchLogoUrlFailed" ?~> s"for dataset ${dataset._id}"
isEditable <- isEditableBy(dataset, requestingUserOpt, requestingUserTeamManagerMemberships) ?~> "dataset.list.isEditableCheckFailed" ?~> s"for dataset ${dataset._id}"
lastUsedByUser <- lastUsedTimeFor(dataset._id, requestingUserOpt) ?~> "dataset.list.fetchLastUsedTimeFailed" ?~> s"for dataset ${dataset._id}"
dataStoreJs <- dataStoreService.publicWrites(dataStore) ?~> "dataset.list.dataStoreWritesFailed" ?~> s"for dataset ${dataset._id}"
dataSource <- dataSourceFor(dataset, Some(organization)) ?~> "dataset.list.fetchDataSourceFailed" ?~> s"for dataset ${dataset._id}"
usedStorageBytes <- Fox.runIf(requestingUserOpt.exists(u => u._organization == dataset._organization))(
organizationDAO.getUsedStorageForDataset(dataset._id))
organizationDAO.getUsedStorageForDataset(dataset._id)) ?~> s"fetching used storage failed for ${dataset._id}"
} yield {
Json.obj(
"id" -> dataset._id,
Expand Down