Skip to content
Snippets Groups Projects
Commit 92dd4ff4 authored by Martin Weise's avatar Martin Weise
Browse files

More debug duration log

parent 26886557
No related branches found
No related tags found
1 merge request!424More debug duration log
Show whitespace changes
Inline Side-by-side
Showing
with 337 additions and 77 deletions
dbrepo-auth-service/listeners/create-event-listener.jar
+ 0
− 0
View file @ 92dd4ff4
No preview for this file type
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/AccessServiceMariaDbImpl.java
+ 35
− 7
View file @ 92dd4ff4
...@@ -42,22 +42,38 @@ public class AccessServiceMariaDbImpl extends DataConnector implements AccessSer ...@@ -42,22 +42,38 @@ public class AccessServiceMariaDbImpl extends DataConnector implements AccessSer
long start = System.currentTimeMillis(); long start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseCreateUserQuery(user.getUsername(), user.getPassword())) connection.prepareStatement(mariaDbMapper.databaseCreateUserQuery(user.getUsername(), user.getPassword()))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("create user in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "create_user")
.log();
/* grant access */ /* grant access */
final String grants = access != AccessTypeDto.READ ? grantDefaultWrite : grantDefaultRead; final String grants = access != AccessTypeDto.READ ? grantDefaultWrite : grantDefaultRead;
start = System.currentTimeMillis(); start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseGrantPrivilegesQuery(user.getUsername(), grants)) connection.prepareStatement(mariaDbMapper.databaseGrantPrivilegesQuery(user.getUsername(), grants))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("grant user privileges in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "grant_user_privileges")
.log();
/* grant query store */ /* grant query store */
start = System.currentTimeMillis(); start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseGrantProcedureQuery(user.getUsername(), "store_query")) connection.prepareStatement(mariaDbMapper.databaseGrantProcedureQuery(user.getUsername(), "store_query"))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("grant procedure privileges in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "grant_procedure_privileges")
.log();
/* apply access rights */ /* apply access rights */
start = System.currentTimeMillis(); start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseFlushPrivilegesQuery()); connection.prepareStatement(mariaDbMapper.databaseFlushPrivilegesQuery());
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("flush privileges in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "flush_privileges")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
...@@ -81,7 +97,11 @@ public class AccessServiceMariaDbImpl extends DataConnector implements AccessSer ...@@ -81,7 +97,11 @@ public class AccessServiceMariaDbImpl extends DataConnector implements AccessSer
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseGrantPrivilegesQuery(user.getUsername(), grants)) connection.prepareStatement(mariaDbMapper.databaseGrantPrivilegesQuery(user.getUsername(), grants))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("update privileges in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "grant_user_privileges")
.log();
/* apply access rights */ /* apply access rights */
connection.prepareStatement(mariaDbMapper.databaseFlushPrivilegesQuery()); connection.prepareStatement(mariaDbMapper.databaseFlushPrivilegesQuery());
connection.commit(); connection.commit();
...@@ -105,12 +125,20 @@ public class AccessServiceMariaDbImpl extends DataConnector implements AccessSer ...@@ -105,12 +125,20 @@ public class AccessServiceMariaDbImpl extends DataConnector implements AccessSer
long start = System.currentTimeMillis(); long start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseRevokePrivilegesQuery(user.getUsername())) connection.prepareStatement(mariaDbMapper.databaseRevokePrivilegesQuery(user.getUsername()))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("revoke privileges in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "grant_user_privileges")
.log();
/* apply access rights */ /* apply access rights */
start = System.currentTimeMillis(); start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseFlushPrivilegesQuery()) connection.prepareStatement(mariaDbMapper.databaseFlushPrivilegesQuery())
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("flush privileges in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "flush_privileges")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
......
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/CacheServiceImpl.java
+ 56
− 14
View file @ 92dd4ff4
...@@ -56,10 +56,16 @@ public class CacheServiceImpl implements CacheService { ...@@ -56,10 +56,16 @@ public class CacheServiceImpl implements CacheService {
if (!forceReload) { if (!forceReload) {
final DatabaseDto cacheDatabase = databaseCache.getIfPresent(id); final DatabaseDto cacheDatabase = databaseCache.getIfPresent(id);
if (cacheDatabase != null) { if (cacheDatabase != null) {
log.trace("found database with id {} in cache", id); log.atTrace()
.setMessage("found database with id " + id + " in cache")
.addKeyValue("cache_hit", true)
.log();
return cacheDatabase; return cacheDatabase;
} }
log.debug("database with id {} not it cache (anymore): reload from metadata service", id); log.atTrace()
.setMessage("reload database from metadata service with id " + id + " in cache")
.addKeyValue("cache_hit", false)
.log();
} }
final DatabaseDto database = gateway.getDatabaseById(id); final DatabaseDto database = gateway.getDatabaseById(id);
databaseCache.put(id, database); databaseCache.put(id, database);
...@@ -77,10 +83,16 @@ public class CacheServiceImpl implements CacheService { ...@@ -77,10 +83,16 @@ public class CacheServiceImpl implements CacheService {
MetadataServiceException, TableNotFoundException { MetadataServiceException, TableNotFoundException {
final TableDto cacheTable = tableCache.getIfPresent(tableId); final TableDto cacheTable = tableCache.getIfPresent(tableId);
if (cacheTable != null) { if (cacheTable != null) {
log.trace("found table with id {} in cache", tableId); log.atTrace()
.setMessage("found table with id " + tableId + " in cache")
.addKeyValue("cache_hit", true)
.log();
return cacheTable; return cacheTable;
} }
log.debug("table with id {} not it cache (anymore): reload from metadata service", tableId); log.atTrace()
.setMessage("reload table from metadata service with id " + tableId + " in cache")
.addKeyValue("cache_hit", false)
.log();
final TableDto table = gateway.getTableById(databaseId, tableId); final TableDto table = gateway.getTableById(databaseId, tableId);
tableCache.put(tableId, table); tableCache.put(tableId, table);
return table; return table;
...@@ -91,10 +103,16 @@ public class CacheServiceImpl implements CacheService { ...@@ -91,10 +103,16 @@ public class CacheServiceImpl implements CacheService {
TableMalformedException, QueryMalformedException, SQLException { TableMalformedException, QueryMalformedException, SQLException {
final TableStatisticDto cacheStatistic = statisticCache.getIfPresent(view.getId()); final TableStatisticDto cacheStatistic = statisticCache.getIfPresent(view.getId());
if (cacheStatistic != null) { if (cacheStatistic != null) {
log.trace("found view statistic with id {} in cache", view.getId()); log.atTrace()
.setMessage("found view with id " + view.getId() + " in cache")
.addKeyValue("cache_hit", true)
.log();
return cacheStatistic; return cacheStatistic;
} }
log.debug("view statistic with id {} not it cache (anymore): reload", view.getId()); log.atTrace()
.setMessage("reload view from metadata service with id " + view.getId() + " in cache")
.addKeyValue("cache_hit", false)
.log();
final TableStatisticDto statistic = tableService.getStatistics(database, view.getInternalName()); final TableStatisticDto statistic = tableService.getStatistics(database, view.getInternalName());
statistic.setTotalRows(tableService.getCount(database, view.getInternalName(), Instant.now())); statistic.setTotalRows(tableService.getCount(database, view.getInternalName(), Instant.now()));
statisticCache.put(view.getId(), statistic); statisticCache.put(view.getId(), statistic);
...@@ -106,10 +124,16 @@ public class CacheServiceImpl implements CacheService { ...@@ -106,10 +124,16 @@ public class CacheServiceImpl implements CacheService {
ContainerNotFoundException { ContainerNotFoundException {
final ContainerDto cacheContainer = containerCache.getIfPresent(id); final ContainerDto cacheContainer = containerCache.getIfPresent(id);
if (cacheContainer != null) { if (cacheContainer != null) {
log.trace("found container with id {} in cache", id); log.atTrace()
.setMessage("found container with id " + id + " in cache")
.addKeyValue("cache_hit", true)
.log();
return cacheContainer; return cacheContainer;
} }
log.debug("container with id {} not it cache (anymore): reload from metadata service", id); log.atTrace()
.setMessage("reload container from metadata service with id " + id + " in cache")
.addKeyValue("cache_hit", false)
.log();
final ContainerDto container = gateway.getContainerById(id); final ContainerDto container = gateway.getContainerById(id);
containerCache.put(id, container); containerCache.put(id, container);
return container; return container;
...@@ -120,10 +144,16 @@ public class CacheServiceImpl implements CacheService { ...@@ -120,10 +144,16 @@ public class CacheServiceImpl implements CacheService {
MetadataServiceException, ViewNotFoundException { MetadataServiceException, ViewNotFoundException {
final ViewDto cacheView = viewCache.getIfPresent(viewId); final ViewDto cacheView = viewCache.getIfPresent(viewId);
if (cacheView != null) { if (cacheView != null) {
log.trace("found view with id {} in cache", viewId); log.atTrace()
.setMessage("found view with id " + viewId + " in cache")
.addKeyValue("cache_hit", true)
.log();
return cacheView; return cacheView;
} }
log.debug("view with id {} not it cache (anymore): reload from metadata service", viewId); log.atTrace()
.setMessage("reload view from metadata service with id " + viewId + " in cache")
.addKeyValue("cache_hit", false)
.log();
final ViewDto view = gateway.getViewById(databaseId, viewId); final ViewDto view = gateway.getViewById(databaseId, viewId);
viewCache.put(viewId, view); viewCache.put(viewId, view);
return view; return view;
...@@ -134,10 +164,16 @@ public class CacheServiceImpl implements CacheService { ...@@ -134,10 +164,16 @@ public class CacheServiceImpl implements CacheService {
UserNotFoundException { UserNotFoundException {
final UserDto cacheUser = userCache.getIfPresent(id); final UserDto cacheUser = userCache.getIfPresent(id);
if (cacheUser != null) { if (cacheUser != null) {
log.trace("found user with id {} in cache", id); log.atTrace()
.setMessage("found user with id " + id + " in cache")
.addKeyValue("cache_hit", true)
.log();
return cacheUser; return cacheUser;
} }
log.debug("user with id {} not it cache (anymore): reload from metadata service", id); log.atTrace()
.setMessage("reload user from metadata service with id " + id + " in cache")
.addKeyValue("cache_hit", false)
.log();
final UserDto user = gateway.getUserById(id); final UserDto user = gateway.getUserById(id);
userCache.put(id, user); userCache.put(id, user);
return user; return user;
...@@ -148,10 +184,16 @@ public class CacheServiceImpl implements CacheService { ...@@ -148,10 +184,16 @@ public class CacheServiceImpl implements CacheService {
MetadataServiceException, NotAllowedException { MetadataServiceException, NotAllowedException {
final DatabaseAccessDto cacheAccess = accessCache.getIfPresent(databaseId); final DatabaseAccessDto cacheAccess = accessCache.getIfPresent(databaseId);
if (cacheAccess != null) { if (cacheAccess != null) {
log.trace("found access for user with id {} to database with id {} in cache", userId, databaseId); log.atTrace()
.setMessage("found access for user with id " + userId + " in cache")
.addKeyValue("cache_hit", true)
.log();
return cacheAccess; return cacheAccess;
} }
log.debug("access for user with id {} to database with id {} not it cache (anymore): reload from metadata service", userId, databaseId); log.atTrace()
.setMessage("reload access from metadata service with user id " + userId + " in cache")
.addKeyValue("cache_hit", false)
.log();
final DatabaseAccessDto access = gateway.getAccess(databaseId, userId); final DatabaseAccessDto access = gateway.getAccess(databaseId, userId);
accessCache.put(databaseId, access); accessCache.put(databaseId, access);
return access; return access;
......
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/ContainerServiceMariaDbImpl.java
+ 26
− 7
View file @ 92dd4ff4
package at.ac.tuwien.ifs.dbrepo.service.impl; package at.ac.tuwien.ifs.dbrepo.service.impl;
import at.ac.tuwien.ifs.dbrepo.config.RabbitConfig;
import at.ac.tuwien.ifs.dbrepo.core.api.container.ContainerDto; import at.ac.tuwien.ifs.dbrepo.core.api.container.ContainerDto;
import at.ac.tuwien.ifs.dbrepo.core.api.database.DatabaseDto; import at.ac.tuwien.ifs.dbrepo.core.api.database.DatabaseDto;
import at.ac.tuwien.ifs.dbrepo.core.api.database.internal.CreateDatabaseDto; import at.ac.tuwien.ifs.dbrepo.core.api.database.internal.CreateDatabaseDto;
import at.ac.tuwien.ifs.dbrepo.core.api.user.UserBriefDto; import at.ac.tuwien.ifs.dbrepo.core.api.user.UserBriefDto;
import at.ac.tuwien.ifs.dbrepo.core.exception.DatabaseMalformedException; import at.ac.tuwien.ifs.dbrepo.core.exception.DatabaseMalformedException;
import at.ac.tuwien.ifs.dbrepo.core.exception.QueryStoreCreateException; import at.ac.tuwien.ifs.dbrepo.core.exception.QueryStoreCreateException;
import at.ac.tuwien.ifs.dbrepo.config.RabbitConfig;
import at.ac.tuwien.ifs.dbrepo.mapper.MariaDbMapper; import at.ac.tuwien.ifs.dbrepo.mapper.MariaDbMapper;
import at.ac.tuwien.ifs.dbrepo.service.ContainerService; import at.ac.tuwien.ifs.dbrepo.service.ContainerService;
import com.mchange.v2.c3p0.ComboPooledDataSource; import com.mchange.v2.c3p0.ComboPooledDataSource;
import lombok.extern.slf4j.Slf4j; import lombok.extern.slf4j.Slf4j;
import org.apache.logging.log4j.message.MapMessage;
import org.springframework.beans.factory.annotation.Autowired; import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Service; import org.springframework.stereotype.Service;
...@@ -41,8 +40,12 @@ public class ContainerServiceMariaDbImpl extends DataConnector implements Contai ...@@ -41,8 +40,12 @@ public class ContainerServiceMariaDbImpl extends DataConnector implements Contai
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseCreateDatabaseQuery(data.getInternalName())) connection.prepareStatement(mariaDbMapper.databaseCreateDatabaseQuery(data.getInternalName()))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start);
connection.commit(); connection.commit();
log.atDebug()
.setMessage("created database: " + data.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "create_database")
.log();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
log.error("Failed to create database access: {}", e.getMessage()); log.error("Failed to create database access: {}", e.getMessage());
...@@ -74,19 +77,35 @@ public class ContainerServiceMariaDbImpl extends DataConnector implements Contai ...@@ -74,19 +77,35 @@ public class ContainerServiceMariaDbImpl extends DataConnector implements Contai
long start = System.currentTimeMillis(); long start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.queryStoreCreateTableRawQuery()) connection.prepareStatement(mariaDbMapper.queryStoreCreateTableRawQuery())
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("created query store in database: " + databaseName)
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "create_query_store")
.log();
start = System.currentTimeMillis(); start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.queryStoreCreateHashTableProcedureRawQuery()) connection.prepareStatement(mariaDbMapper.queryStoreCreateHashTableProcedureRawQuery())
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("created query store hash table procedure in database: " + databaseName)
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "create_procedure_hash_table")
.log();
start = System.currentTimeMillis(); start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.queryStoreCreateStoreQueryProcedureRawQuery()) connection.prepareStatement(mariaDbMapper.queryStoreCreateStoreQueryProcedureRawQuery())
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("created query store procedure in database: " + databaseName)
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "create_procedure_store_query")
.log();
start = System.currentTimeMillis(); start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.queryStoreCreateInternalStoreQueryProcedureRawQuery()) connection.prepareStatement(mariaDbMapper.queryStoreCreateInternalStoreQueryProcedureRawQuery())
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("created internal query store procedure in database: " + databaseName)
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "create_procedure_internal_store_query")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
......
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/DatabaseServiceMariaDbImpl.java
+ 65
− 17
View file @ 92dd4ff4
package at.ac.tuwien.ifs.dbrepo.service.impl; package at.ac.tuwien.ifs.dbrepo.service.impl;
import at.ac.tuwien.ifs.dbrepo.mapper.DataMapper;
import at.ac.tuwien.ifs.dbrepo.mapper.MariaDbMapper;
import at.ac.tuwien.ifs.dbrepo.service.DatabaseService;
import at.ac.tuwien.ifs.dbrepo.core.api.database.DatabaseDto; import at.ac.tuwien.ifs.dbrepo.core.api.database.DatabaseDto;
import at.ac.tuwien.ifs.dbrepo.core.api.database.ViewDto; import at.ac.tuwien.ifs.dbrepo.core.api.database.ViewDto;
import at.ac.tuwien.ifs.dbrepo.core.api.database.table.TableDto; import at.ac.tuwien.ifs.dbrepo.core.api.database.table.TableDto;
...@@ -10,6 +7,9 @@ import at.ac.tuwien.ifs.dbrepo.core.api.database.table.constraints.unique.Unique ...@@ -10,6 +7,9 @@ import at.ac.tuwien.ifs.dbrepo.core.api.database.table.constraints.unique.Unique
import at.ac.tuwien.ifs.dbrepo.core.api.database.table.internal.TableCreateDto; import at.ac.tuwien.ifs.dbrepo.core.api.database.table.internal.TableCreateDto;
import at.ac.tuwien.ifs.dbrepo.core.api.user.internal.UpdateUserPasswordDto; import at.ac.tuwien.ifs.dbrepo.core.api.user.internal.UpdateUserPasswordDto;
import at.ac.tuwien.ifs.dbrepo.core.exception.*; import at.ac.tuwien.ifs.dbrepo.core.exception.*;
import at.ac.tuwien.ifs.dbrepo.mapper.DataMapper;
import at.ac.tuwien.ifs.dbrepo.mapper.MariaDbMapper;
import at.ac.tuwien.ifs.dbrepo.service.DatabaseService;
import com.google.common.hash.Hashing; import com.google.common.hash.Hashing;
import com.mchange.v2.c3p0.ComboPooledDataSource; import com.mchange.v2.c3p0.ComboPooledDataSource;
import lombok.extern.slf4j.Slf4j; import lombok.extern.slf4j.Slf4j;
...@@ -49,7 +49,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -49,7 +49,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
statement1.setString(2, viewName); statement1.setString(2, viewName);
log.trace("1={}, 2={}", database.getInternalName(), viewName); log.trace("1={}, 2={}", database.getInternalName(), viewName);
final ResultSet resultSet1 = statement1.executeQuery(); final ResultSet resultSet1 = statement1.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("inspected view: " + viewName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_view_schema")
.log();
if (!resultSet1.next()) { if (!resultSet1.next()) {
throw new ViewNotFoundException("Failed to find view in the information schema"); throw new ViewNotFoundException("Failed to find view in the information schema");
} }
...@@ -63,7 +67,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -63,7 +67,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
statement2.setString(2, view.getInternalName()); statement2.setString(2, view.getInternalName());
log.trace("1={}, 2={}", database.getInternalName(), view.getInternalName()); log.trace("1={}, 2={}", database.getInternalName(), view.getInternalName());
final ResultSet resultSet2 = statement2.executeQuery(); final ResultSet resultSet2 = statement2.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("inspect view columns: " + viewName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_view_columns")
.log();
TableDto tmp = TableDto.builder() TableDto tmp = TableDto.builder()
.columns(new LinkedList<>()) .columns(new LinkedList<>())
.build(); .build();
...@@ -95,7 +103,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -95,7 +103,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
connection.prepareStatement(mariaDbMapper.tableCreateDtoToCreateTableRawQuery(database.getInternalName(), connection.prepareStatement(mariaDbMapper.tableCreateDtoToCreateTableRawQuery(database.getInternalName(),
data)) data))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("created table: " + tableName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "create_table")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
...@@ -131,24 +143,32 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -131,24 +143,32 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
.databaseId(database.getId()) .databaseId(database.getId())
.columns(new LinkedList<>()) .columns(new LinkedList<>())
.build(); .build();
log.debug("creating view: {}.{}", database.getInternalName(), view.getInternalName());
try { try {
/* create view if not exists */ /* create view if not exists */
final long start = System.currentTimeMillis(); long start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.viewCreateRawQuery(view.getInternalName(), query)) connection.prepareStatement(mariaDbMapper.viewCreateRawQuery(view.getInternalName(), query))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("created view: " + view.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "create_view")
.log();
/* select view columns */ /* select view columns */
start = System.currentTimeMillis();
final PreparedStatement statement2 = connection.prepareStatement(mariaDbMapper.databaseTableColumnsSelectRawQuery()); final PreparedStatement statement2 = connection.prepareStatement(mariaDbMapper.databaseTableColumnsSelectRawQuery());
statement2.setString(1, database.getInternalName()); statement2.setString(1, database.getInternalName());
statement2.setString(2, view.getInternalName()); statement2.setString(2, view.getInternalName());
final ResultSet resultSet2 = statement2.executeQuery(); final ResultSet resultSet2 = statement2.executeQuery();
log.atDebug()
.setMessage("created view: " + view.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_view_columns")
.log();
while (resultSet2.next()) { while (resultSet2.next()) {
view = dataMapper.resultSetToTable(resultSet2, view); view = dataMapper.resultSetToTable(resultSet2, view);
} }
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
log.error("Failed to create table", e);
connection.rollback(); connection.rollback();
log.error("Failed to create view: {}", e.getMessage()); log.error("Failed to create view: {}", e.getMessage());
throw new ViewMalformedException("Failed to create view: " + e.getMessage(), e); throw new ViewMalformedException("Failed to create view: " + e.getMessage(), e);
...@@ -171,7 +191,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -171,7 +191,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
statement.setString(1, database.getInternalName()); statement.setString(1, database.getInternalName());
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
final ResultSet resultSet1 = statement.executeQuery(); final ResultSet resultSet1 = statement.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("explored views in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_views")
.log();
while (resultSet1.next()) { while (resultSet1.next()) {
final String viewName = resultSet1.getString(1); final String viewName = resultSet1.getString(1);
if (viewName.length() == 64) { if (viewName.length() == 64) {
...@@ -208,7 +232,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -208,7 +232,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
final PreparedStatement statement = connection.prepareStatement(mariaDbMapper.databaseTablesSelectRawQuery()); final PreparedStatement statement = connection.prepareStatement(mariaDbMapper.databaseTablesSelectRawQuery());
statement.setString(1, database.getInternalName()); statement.setString(1, database.getInternalName());
final ResultSet resultSet1 = statement.executeQuery(); final ResultSet resultSet1 = statement.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("explored tables in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_tables")
.log();
while (resultSet1.next()) { while (resultSet1.next()) {
final String tableName = resultSet1.getString(1); final String tableName = resultSet1.getString(1);
if (database.getTables().stream().anyMatch(t -> t.getInternalName().equals(tableName))) { if (database.getTables().stream().anyMatch(t -> t.getInternalName().equals(tableName))) {
...@@ -243,7 +271,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -243,7 +271,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
statement1.setString(2, tableName); statement1.setString(2, tableName);
log.trace("1={}, 2={}", database.getInternalName(), tableName); log.trace("1={}, 2={}", database.getInternalName(), tableName);
TableDto table = dataMapper.schemaResultSetToTable(database, statement1.executeQuery()); TableDto table = dataMapper.schemaResultSetToTable(database, statement1.executeQuery());
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("inspected table: " + tableName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_table_schema")
.log();
/* obtain columns metadata */ /* obtain columns metadata */
start = System.currentTimeMillis(); start = System.currentTimeMillis();
final PreparedStatement statement2 = connection.prepareStatement(mariaDbMapper.databaseTableColumnsSelectRawQuery()); final PreparedStatement statement2 = connection.prepareStatement(mariaDbMapper.databaseTableColumnsSelectRawQuery());
...@@ -251,7 +283,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -251,7 +283,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
statement2.setString(2, tableName); statement2.setString(2, tableName);
log.trace("1={}, 2={}", database.getInternalName(), tableName); log.trace("1={}, 2={}", database.getInternalName(), tableName);
final ResultSet resultSet2 = statement2.executeQuery(); final ResultSet resultSet2 = statement2.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("inspect table columns: " + tableName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_table_columns")
.log();
while (resultSet2.next()) { while (resultSet2.next()) {
table = dataMapper.resultSetToTable(resultSet2, table); table = dataMapper.resultSetToTable(resultSet2, table);
} }
...@@ -262,7 +298,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -262,7 +298,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
statement3.setString(2, tableName); statement3.setString(2, tableName);
log.trace("1={}, 2={}", database.getInternalName(), tableName); log.trace("1={}, 2={}", database.getInternalName(), tableName);
final ResultSet resultSet3 = statement3.executeQuery(); final ResultSet resultSet3 = statement3.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("inspect table check constraints: " + tableName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_table_constraints_check")
.log();
while (resultSet3.next()) { while (resultSet3.next()) {
final String clause = resultSet3.getString(1); final String clause = resultSet3.getString(1);
table.getConstraints() table.getConstraints()
...@@ -277,7 +317,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -277,7 +317,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
statement4.setString(2, tableName); statement4.setString(2, tableName);
log.trace("1={}, 2={}", database.getInternalName(), tableName); log.trace("1={}, 2={}", database.getInternalName(), tableName);
final ResultSet resultSet4 = statement4.executeQuery(); final ResultSet resultSet4 = statement4.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("inspect table constraints: " + tableName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "select_table_constraints")
.log();
while (resultSet4.next()) { while (resultSet4.next()) {
table = dataMapper.resultSetToConstraint(resultSet4, table); table = dataMapper.resultSetToConstraint(resultSet4, table);
for (UniqueDto uk : table.getConstraints().getUniques()) { for (UniqueDto uk : table.getConstraints().getUniques()) {
...@@ -315,7 +359,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas ...@@ -315,7 +359,11 @@ public class DatabaseServiceMariaDbImpl extends DataConnector implements Databas
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.databaseSetPasswordQuery(data.getUsername(), data.getPassword())) connection.prepareStatement(mariaDbMapper.databaseSetPasswordQuery(data.getUsername(), data.getPassword()))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("updated user password: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "update_user_password")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
......
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/QueueServiceRabbitMqImpl.java
+ 5
− 2
View file @ 92dd4ff4
...@@ -47,8 +47,11 @@ public class QueueServiceRabbitMqImpl extends DataConnector implements QueueServ ...@@ -47,8 +47,11 @@ public class QueueServiceRabbitMqImpl extends DataConnector implements QueueServ
} }
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
preparedStatement.executeUpdate(); preparedStatement.executeUpdate();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
log.trace("successfully inserted tuple"); .setMessage("successfully inserted tuple")
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "insert_tuple")
.log();
} finally { } finally {
dataSource.close(); dataSource.close();
} }
......
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/StorageServiceS3Impl.java
+ 32
− 7
View file @ 92dd4ff4
...@@ -46,21 +46,33 @@ public class StorageServiceS3Impl implements StorageService { ...@@ -46,21 +46,33 @@ public class StorageServiceS3Impl implements StorageService {
@Override @Override
public void putObject(String key, byte[] content) { public void putObject(String key, byte[] content) {
final long start = System.currentTimeMillis();
s3Client.putObject(PutObjectRequest.builder() s3Client.putObject(PutObjectRequest.builder()
.key(key) .key(key)
.bucket(s3Config.getS3Bucket()) .bucket(s3Config.getS3Bucket())
.build(), RequestBody.fromBytes(content)); .build(), RequestBody.fromBytes(content));
log.debug("put object in S3 bucket {} with key: {}", s3Config.getS3Bucket(), key); log.atDebug()
.setMessage("put object in bucket with key: " + key)
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "s3_put_object")
.log();
} }
@Override @Override
public InputStream getObject(String bucket, String key) throws StorageNotFoundException, public InputStream getObject(String bucket, String key) throws StorageNotFoundException,
StorageUnavailableException { StorageUnavailableException {
try { try {
return s3Client.getObject(GetObjectRequest.builder() final long start = System.currentTimeMillis();
final InputStream object = s3Client.getObject(GetObjectRequest.builder()
.bucket(bucket) .bucket(bucket)
.key(key) .key(key)
.build()); .build());
log.atDebug()
.setMessage("get object from bucket with key: " + key)
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "s3_get_object")
.log();
return object;
} catch (NoSuchKeyException e) { } catch (NoSuchKeyException e) {
log.error("Failed to find object: not found: {}", e.getMessage()); log.error("Failed to find object: not found: {}", e.getMessage());
throw new StorageNotFoundException("Failed to find object: not found: " + e.getMessage(), e); throw new StorageNotFoundException("Failed to find object: not found: " + e.getMessage(), e);
...@@ -88,19 +100,21 @@ public class StorageServiceS3Impl implements StorageService { ...@@ -88,19 +100,21 @@ public class StorageServiceS3Impl implements StorageService {
@Override @Override
public void deleteObject(String key) { public void deleteObject(String key) {
final long start = System.currentTimeMillis();
s3Client.deleteObject(DeleteObjectRequest.builder() s3Client.deleteObject(DeleteObjectRequest.builder()
.bucket(s3Config.getS3Bucket()) .bucket(s3Config.getS3Bucket())
.key(key) .key(key)
.build()); .build());
log.atDebug() log.atDebug()
.setMessage("deleted object " + key + " in bucket " + s3Config.getS3Bucket()) .setMessage("delete object from bucket with key: " + key)
.addKeyValue("key", key) .addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("bucket", s3Config.getS3Bucket()) .addKeyValue("action", "s3_delete_object")
.log(); .log();
} }
@Override @Override
public ExportResourceDto transformDataset(Dataset<Row> dataset) throws StorageUnavailableException { public ExportResourceDto transformDataset(Dataset<Row> dataset) throws StorageUnavailableException {
long start = System.currentTimeMillis();
final List<Map<String, String>> inMemory = dataset.collectAsList() final List<Map<String, String>> inMemory = dataset.collectAsList()
.stream() .stream()
.map(row -> { .map(row -> {
...@@ -111,7 +125,12 @@ public class StorageServiceS3Impl implements StorageService { ...@@ -111,7 +125,12 @@ public class StorageServiceS3Impl implements StorageService {
return map; return map;
}) })
.toList(); .toList();
log.debug("collected dataset with {} row(s)", inMemory.size()); log.atDebug()
.setMessage("transformed dataset with rows: " + inMemory.size())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "dataset_transform")
.log();
start = System.currentTimeMillis();
try { try {
final ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream(); final ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream();
try (Writer w = new OutputStreamWriter(byteArrayOutputStream, Charset.defaultCharset())) { try (Writer w = new OutputStreamWriter(byteArrayOutputStream, Charset.defaultCharset())) {
...@@ -131,9 +150,15 @@ public class StorageServiceS3Impl implements StorageService { ...@@ -131,9 +150,15 @@ public class StorageServiceS3Impl implements StorageService {
} }
w.flush(); w.flush();
} }
final InputStreamResource resource = new InputStreamResource(new ByteArrayInputStream(byteArrayOutputStream.toByteArray()));
log.atDebug()
.setMessage("transformed dataset to input stream resource")
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "dataset_export")
.log();
return ExportResourceDto.builder() return ExportResourceDto.builder()
.filename("dataset.csv") .filename("dataset.csv")
.resource(new InputStreamResource(new ByteArrayInputStream(byteArrayOutputStream.toByteArray()))) .resource(resource)
.build(); .build();
} catch (IOException e) { } catch (IOException e) {
log.error("Failed to transform in-memory dataset: {}", e.getMessage()); log.error("Failed to transform in-memory dataset: {}", e.getMessage());
......
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/SubsetServiceMariaDbImpl.java
+ 42
− 7
View file @ 92dd4ff4
...@@ -50,13 +50,20 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer ...@@ -50,13 +50,20 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer
@Override @Override
public Dataset<Row> getData(DatabaseDto database, String query) throws QueryMalformedException, TableNotFoundException { public Dataset<Row> getData(DatabaseDto database, String query) throws QueryMalformedException, TableNotFoundException {
try { try {
return sparkSession.read() final long start = System.currentTimeMillis();
final Dataset<Row> dataset = sparkSession.read()
.format("jdbc") .format("jdbc")
.option("user", database.getContainer().getUsername()) .option("user", database.getContainer().getUsername())
.option("password", database.getContainer().getPassword()) .option("password", database.getContainer().getPassword())
.option("url", getSparkUrl(database)) .option("url", getSparkUrl(database))
.option("query", query) .option("query", query)
.load(); .load();
log.atDebug()
.setMessage("get data from url: " + getSparkUrl(database))
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "jdbc_get_data")
.log();
return dataset;
} catch (Exception e) { } catch (Exception e) {
if (e instanceof ExtendedAnalysisException && e.getMessage().contains("TABLE_OR_VIEW_NOT_FOUND") if (e instanceof ExtendedAnalysisException && e.getMessage().contains("TABLE_OR_VIEW_NOT_FOUND")
|| e instanceof SQLSyntaxErrorException && e.getMessage().contains("doesn't exist")) { || e instanceof SQLSyntaxErrorException && e.getMessage().contains("doesn't exist")) {
...@@ -98,7 +105,11 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer ...@@ -98,7 +105,11 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer
log.trace("filter persisted only {}", filterPersisted); log.trace("filter persisted only {}", filterPersisted);
} }
final ResultSet resultSet = statement.executeQuery(); final ResultSet resultSet = statement.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("list subsets in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "list_queries")
.log();
final List<QueryDto> queries = new LinkedList<>(); final List<QueryDto> queries = new LinkedList<>();
while (resultSet.next()) { while (resultSet.next()) {
final QueryDto query = dataMapper.resultSetToQueryDto(resultSet); final QueryDto query = dataMapper.resultSetToQueryDto(resultSet);
...@@ -132,7 +143,13 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer ...@@ -132,7 +143,13 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
final ResultSet resultSet = connection.prepareStatement(mariaDbMapper.countRawSelectQuery(statement, timestamp)) final ResultSet resultSet = connection.prepareStatement(mariaDbMapper.countRawSelectQuery(statement, timestamp))
.executeQuery(); .executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("count subset in database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "count_query")
.addKeyValue("query", statement)
.addKeyValue("timestamp", timestamp)
.log();
return mariaDbMapper.resultSetToNumber(resultSet); return mariaDbMapper.resultSetToNumber(resultSet);
} catch (SQLException e) { } catch (SQLException e) {
log.error("Failed to map object: {}", e.getMessage()); log.error("Failed to map object: {}", e.getMessage());
...@@ -152,7 +169,11 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer ...@@ -152,7 +169,11 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer
final PreparedStatement preparedStatement = connection.prepareStatement(mariaDbMapper.queryStoreFindQueryRawQuery()); final PreparedStatement preparedStatement = connection.prepareStatement(mariaDbMapper.queryStoreFindQueryRawQuery());
preparedStatement.setString(1, String.valueOf(queryId)); preparedStatement.setString(1, String.valueOf(queryId));
final ResultSet resultSet = preparedStatement.executeQuery(); final ResultSet resultSet = preparedStatement.executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("find query in query store of database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "find_query")
.log();
if (!resultSet.next()) { if (!resultSet.next()) {
throw new QueryNotFoundException("Failed to find query"); throw new QueryNotFoundException("Failed to find query");
} }
...@@ -190,7 +211,12 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer ...@@ -190,7 +211,12 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer
callableStatement.setTimestamp(3, Timestamp.from(timestamp)); callableStatement.setTimestamp(3, Timestamp.from(timestamp));
callableStatement.registerOutParameter(4, Types.VARCHAR); callableStatement.registerOutParameter(4, Types.VARCHAR);
callableStatement.executeUpdate(); callableStatement.executeUpdate();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("store query in query store of database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "store_query")
.addKeyValue("query", query)
.log();
queryId = UUID.fromString(callableStatement.getString(4)); queryId = UUID.fromString(callableStatement.getString(4));
callableStatement.close(); callableStatement.close();
log.info("Stored query with id {} in database with name {}", queryId, database.getInternalName()); log.info("Stored query with id {} in database with name {}", queryId, database.getInternalName());
...@@ -217,7 +243,12 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer ...@@ -217,7 +243,12 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer
preparedStatement.setBoolean(1, persist); preparedStatement.setBoolean(1, persist);
preparedStatement.setString(2, String.valueOf(queryId)); preparedStatement.setString(2, String.valueOf(queryId));
preparedStatement.executeUpdate(); preparedStatement.executeUpdate();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("persist query in query store of database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "persist_query")
.addKeyValue("query_id", queryId)
.log();
} catch (SQLException e) { } catch (SQLException e) {
log.error("Failed to (un-)persist query: {}", e.getMessage()); log.error("Failed to (un-)persist query: {}", e.getMessage());
throw new QueryStorePersistException("Failed to (un-)persist query", e); throw new QueryStorePersistException("Failed to (un-)persist query", e);
...@@ -235,7 +266,11 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer ...@@ -235,7 +266,11 @@ public class SubsetServiceMariaDbImpl extends DataConnector implements SubsetSer
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.queryStoreDeleteStaleQueriesRawQuery()) connection.prepareStatement(mariaDbMapper.queryStoreDeleteStaleQueriesRawQuery())
.executeUpdate(); .executeUpdate();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("delete stale queries in query store of database: " + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "delete_stale_queries")
.log();
} catch (SQLException e) { } catch (SQLException e) {
log.error("Failed to delete stale queries: {}", e.getMessage()); log.error("Failed to delete stale queries: {}", e.getMessage());
throw new QueryStoreGCException("Failed to delete stale queries: " + e.getMessage(), e); throw new QueryStoreGCException("Failed to delete stale queries: " + e.getMessage(), e);
......
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/TableServiceMariaDbImpl.java
+ 66
− 14
View file @ 92dd4ff4
...@@ -69,7 +69,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -69,7 +69,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
statistic = dataMapper.resultSetToTableStatistic(resultSet); statistic = dataMapper.resultSetToTableStatistic(resultSet);
statistic.setTotalColumns(Long.parseLong("" + tmpTable.getColumns() statistic.setTotalColumns(Long.parseLong("" + tmpTable.getColumns()
.size())); .size()));
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("get table statistics: " + tableName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "get_table_statistics")
.log();
statistic.setAvgRowLength(tmpTable.getAvgRowLength()); statistic.setAvgRowLength(tmpTable.getAvgRowLength());
statistic.setDataLength(tmpTable.getDataLength()); statistic.setDataLength(tmpTable.getDataLength());
statistic.setMaxDataLength(tmpTable.getMaxDataLength()); statistic.setMaxDataLength(tmpTable.getMaxDataLength());
...@@ -102,14 +106,18 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -102,14 +106,18 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
final PreparedStatement statement = connection.prepareStatement( final PreparedStatement statement = connection.prepareStatement(
mariaDbMapper.tableNameToUpdateTableRawQuery(database.getInternalName(), table.getInternalName())); mariaDbMapper.tableNameToUpdateTableRawQuery(database.getInternalName(), table.getInternalName()));
log.trace("prepare with arg 1={}", data.getDescription()); log.trace("1={}", data.getDescription());
if (data.getDescription() == null) { if (data.getDescription() == null) {
statement.setString(1, ""); statement.setString(1, "");
} else { } else {
statement.setString(1, data.getDescription()); statement.setString(1, data.getDescription());
} }
statement.executeUpdate(); statement.executeUpdate();
log.debug(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("update table comment: " + table.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "update_table_comment")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
...@@ -131,7 +139,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -131,7 +139,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
connection.prepareStatement(mariaDbMapper.dropTableRawQuery(database.getInternalName(), connection.prepareStatement(mariaDbMapper.dropTableRawQuery(database.getInternalName(),
table.getInternalName())) table.getInternalName()))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("delete table: " + table.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "delete_table")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
...@@ -155,7 +167,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -155,7 +167,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
final ResultSet resultSet = connection.prepareStatement(mariaDbMapper.selectHistoryRawQuery( final ResultSet resultSet = connection.prepareStatement(mariaDbMapper.selectHistoryRawQuery(
database.getInternalName(), table.getInternalName(), size)) database.getInternalName(), table.getInternalName(), size))
.executeQuery(); .executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("get table history: " + table.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "get_table_history")
.log();
history = dataMapper.resultSetToTableHistory(resultSet); history = dataMapper.resultSetToTableHistory(resultSet);
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
...@@ -181,7 +197,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -181,7 +197,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
final ResultSet resultSet = connection.prepareStatement(mariaDbMapper.selectCountRawQuery( final ResultSet resultSet = connection.prepareStatement(mariaDbMapper.selectCountRawQuery(
database.getInternalName(), tableName, timestamp)) database.getInternalName(), tableName, timestamp))
.executeQuery(); .executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("get table count: " + tableName + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "get_table_count")
.log();
queryResult = mariaDbMapper.resultSetToNumber(resultSet); queryResult = mariaDbMapper.resultSetToNumber(resultSet);
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
...@@ -211,11 +231,17 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -211,11 +231,17 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
final String temporaryTable = table.getInternalName() + "_tmp"; final String temporaryTable = table.getInternalName() + "_tmp";
final ComboPooledDataSource dataSource = getDataSource(database); final ComboPooledDataSource dataSource = getDataSource(database);
final Connection connection = dataSource.getConnection(); final Connection connection = dataSource.getConnection();
long start = System.currentTimeMillis();
try { try {
/* import tuple */ /* import tuple */
connection.prepareStatement(mariaDbMapper.copyTableSchemaToRawQuery(table.getInternalName(), temporaryTable)) connection.prepareStatement(mariaDbMapper.copyTableSchemaToRawQuery(table.getInternalName(), temporaryTable))
.execute(); .execute();
connection.commit(); connection.commit();
log.atDebug()
.setMessage("copy table schema from " + table.getInternalName() + "." + database.getInternalName() + " into temporary table: " + temporaryTable + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "table_copy_schema")
.log();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
log.atError() log.atError()
...@@ -226,10 +252,16 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -226,10 +252,16 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
} }
log.debug("copied schema from target table {} to import table: {}", table.getInternalName(), temporaryTable); log.debug("copied schema from target table {} to import table: {}", table.getInternalName(), temporaryTable);
try { try {
start = System.currentTimeMillis();
dataset.write() dataset.write()
.mode(SaveMode.Overwrite) .mode(SaveMode.Overwrite)
.option("header", data.getHeader()) .option("header", data.getHeader())
.jdbc(getSparkUrl(database), temporaryTable, properties); .jdbc(getSparkUrl(database), temporaryTable, properties);
log.atDebug()
.setMessage("write data into temporary table: " + temporaryTable + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "table_import_data")
.log();
} catch (Exception e) { } catch (Exception e) {
log.atError() log.atError()
.setMessage("Failed to write dataset: schema malformed") .setMessage("Failed to write dataset: schema malformed")
...@@ -239,10 +271,16 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -239,10 +271,16 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
} }
try { try {
/* import tuple */ /* import tuple */
start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.temporaryTableToRawMergeQuery(temporaryTable, connection.prepareStatement(mariaDbMapper.temporaryTableToRawMergeQuery(temporaryTable,
table.getInternalName(), table.getColumns().stream().map(c -> c.getInternalName()).toList())) table.getInternalName(), table.getColumns().stream().map(c -> c.getInternalName()).toList()))
.execute(); .execute();
connection.commit(); connection.commit();
log.atDebug()
.setMessage("merge data from temporary table " + temporaryTable + "." + database.getInternalName() + " into table: " + table.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "table_merge_data")
.log();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
log.atError() log.atError()
...@@ -252,19 +290,21 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -252,19 +290,21 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
throw new MalformedException("Failed to import tuple: " + e.getMessage(), e); throw new MalformedException("Failed to import tuple: " + e.getMessage(), e);
} finally { } finally {
/* delete temporary table */ /* delete temporary table */
start = System.currentTimeMillis();
connection.prepareStatement(mariaDbMapper.dropTableRawQuery(database.getInternalName(), temporaryTable, connection.prepareStatement(mariaDbMapper.dropTableRawQuery(database.getInternalName(), temporaryTable,
false)) false))
.execute(); .execute();
log.debug("deleted temporary table: {}", temporaryTable); log.debug("deleted temporary table: {}", temporaryTable);
connection.commit(); connection.commit();
log.atDebug()
.setMessage("delete temporary table: " + temporaryTable + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "table_delete_schema")
.log();
dataSource.close(); dataSource.close();
} }
storageService.deleteObject(data.getLocation()); storageService.deleteObject(data.getLocation());
log.atInfo() log.info("Imported dataset into table {}.{}", database.getInternalName(), table.getInternalName());
.setMessage("Imported dataset into table " + database.getInternalName() + "." + table.getInternalName())
.addKeyValue("s3_key", data.getLocation())
.addKeyValue("table_name", database.getInternalName() + "." + table.getInternalName())
.log();
} }
@Override @Override
...@@ -286,7 +326,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -286,7 +326,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
} }
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
statement.executeUpdate(); statement.executeUpdate();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("delete tuple in table: " + table.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "table_delete_tuple")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
...@@ -331,7 +375,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -331,7 +375,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
} }
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
statement.executeUpdate(); statement.executeUpdate();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("create tuple in table: " + table.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "table_create_tuple")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
...@@ -368,7 +416,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi ...@@ -368,7 +416,11 @@ public class TableServiceMariaDbImpl extends DataConnector implements TableServi
} }
final long start = System.currentTimeMillis(); final long start = System.currentTimeMillis();
statement.executeUpdate(); statement.executeUpdate();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("update tuple in table: " + table.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "table_update_tuple")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
......
dbrepo-data-service/services/src/main/java/at/ac/tuwien/ifs/dbrepo/service/impl/ViewServiceMariaDbImpl.java
+ 10
− 2
View file @ 92dd4ff4
...@@ -37,7 +37,11 @@ public class ViewServiceMariaDbImpl extends DataConnector implements ViewService ...@@ -37,7 +37,11 @@ public class ViewServiceMariaDbImpl extends DataConnector implements ViewService
connection.prepareStatement(mariaDbMapper.dropViewRawQuery(database.getInternalName(), connection.prepareStatement(mariaDbMapper.dropViewRawQuery(database.getInternalName(),
view.getInternalName())) view.getInternalName()))
.execute(); .execute();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("delete view: " + view.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "view_delete")
.log();
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
connection.rollback(); connection.rollback();
...@@ -61,7 +65,11 @@ public class ViewServiceMariaDbImpl extends DataConnector implements ViewService ...@@ -61,7 +65,11 @@ public class ViewServiceMariaDbImpl extends DataConnector implements ViewService
final ResultSet resultSet = connection.prepareStatement(mariaDbMapper.selectCountRawQuery( final ResultSet resultSet = connection.prepareStatement(mariaDbMapper.selectCountRawQuery(
database.getInternalName(), view.getInternalName(), timestamp)) database.getInternalName(), view.getInternalName(), timestamp))
.executeQuery(); .executeQuery();
log.trace(EXECUTED_STATEMENT_MS, System.currentTimeMillis() - start); log.atDebug()
.setMessage("count view: " + view.getInternalName() + "." + database.getInternalName())
.addKeyValue("duration", System.currentTimeMillis() - start)
.addKeyValue("action", "count_view")
.log();
queryResult = mariaDbMapper.resultSetToNumber(resultSet); queryResult = mariaDbMapper.resultSetToNumber(resultSet);
connection.commit(); connection.commit();
} catch (SQLException e) { } catch (SQLException e) {
......
helm/dbrepo/files/create-event-listener.jar
+ 0
− 0
View file @ 92dd4ff4
No preview for this file type
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Please register or to comment