From c91a4f6f5b0851362819bf927764c6bc5de2a596 Mon Sep 17 00:00:00 2001
From: gmantele <gmantele@ari.uni-heidelberg.de>
Date: Wed, 17 Sep 2014 20:13:38 +0200
Subject: [PATCH] [TAP,UWS] Manage thrown Error properly in synchronous and
asynchronous jobs execution + Modify some log messages + Add log messages in
JDBCConnection (for add and drop uploaded tables).
---
src/tap/ADQLExecutor.java | 14 +++++++++++++-
src/tap/TAPSyncJob.java | 16 +++++++++++-----
src/tap/db/JDBCConnection.java | 14 ++++++++++++--
src/tap/error/DefaultTAPErrorWriter.java | 8 ++------
src/tap/log/TAPLog.java | 5 ++++-
src/tap/resource/Sync.java | 2 +-
src/uws/job/JobThread.java | 13 ++++++++-----
7 files changed, 51 insertions(+), 21 deletions(-)
diff --git a/src/tap/ADQLExecutor.java b/src/tap/ADQLExecutor.java
index 7acfb28..8ad271f 100644
--- a/src/tap/ADQLExecutor.java
+++ b/src/tap/ADQLExecutor.java
@@ -445,7 +445,7 @@ public class ADQLExecutor {
// Upload them, if needed:
if (tables.length > 0){
- logger.logTAP(LogLevel.INFO, report, "UPLOAD", "Loading uploaded tables (" + tables.length + ")...", null);
+ logger.logTAP(LogLevel.INFO, report, "UPLOADING", "Loading uploaded tables (" + tables.length + ")", null);
try{
uploadSchema = service.getFactory().createUploader(dbConn).upload(tables);
}finally{
@@ -478,6 +478,9 @@ public class ADQLExecutor {
* @throws TAPException If the TAP factory is unable to create the ADQL factory or the query checker.
*/
protected ADQLQuery parseADQL() throws ParseException, InterruptedException, TAPException{
+ // Log the start of the parsing:
+ logger.logTAP(LogLevel.INFO, report, "PARSING", "Parsing ADQL: " + tapParams.getQuery().replaceAll("(\t|\r?\n)+", " "), null);
+
// Get the ADQL factory:
ADQLQueryFactory queryFactory = service.getFactory().createQueryFactory();
@@ -526,7 +529,13 @@ public class ADQLExecutor {
* @see {@link DBConnection#executeQuery(ADQLQuery)}
*/
protected TableIterator executeADQL(final ADQLQuery adql) throws InterruptedException, TAPException{
+ // Log the start of execution:
+ logger.logTAP(LogLevel.INFO, report, "EXECUTING", "Executing ADQL: " + adql.toString().replaceAll("(\t|\r?\n)+", " "), null);
+
+ // Execute the ADQL query:
TableIterator result = dbConn.executeQuery(adql);
+
+ // Log the success or failure:
if (result == null)
logger.logTAP(LogLevel.INFO, report, "END_QUERY", "Query execution aborted after " + (System.currentTimeMillis() - startStep) + "ms!", null);
else
@@ -552,6 +561,9 @@ public class ADQLExecutor {
* @see #writeResult(TableIterator, OutputFormat, OutputStream)
*/
protected final void writeResult(final TableIterator queryResult) throws InterruptedException, TAPException, UWSException{
+ // Log the start of the writing:
+ logger.logTAP(LogLevel.INFO, report, "WRITING_RESULT", "Writing the query result", null);
+
// Get the appropriate result formatter:
OutputFormat formatter = getFormatter();
diff --git a/src/tap/TAPSyncJob.java b/src/tap/TAPSyncJob.java
index 016b0da..92b2a08 100644
--- a/src/tap/TAPSyncJob.java
+++ b/src/tap/TAPSyncJob.java
@@ -229,16 +229,19 @@ public class TAPSyncJob {
// TAP EXCEPTION:
else if (error instanceof TAPException){
// log the error:
- service.getLogger().logTAP(LogLevel.ERROR, this, "SYNC_END", "An error occured while executing the query of the synchronous job " + ID + ": " + error.getMessage(), error);
+ service.getLogger().logTAP(LogLevel.ERROR, this, "SYNC_END", "An error occured while executing the query of the synchronous job " + ID + ".", error);
// report the error to the user:
throw (TAPException)error;
}
// ANY OTHER EXCEPTION:
else{
// log the error:
- service.getLogger().logTAP(LogLevel.FATAL, this, "SYNC_END", "An unexpected error has stopped the execution of the synchronous job " + ID + ": " + error.getMessage(), error);
+ service.getLogger().logTAP(LogLevel.FATAL, this, "SYNC_END", "An unexpected error has stopped the execution of the synchronous job " + ID + ".", error);
// report the error to the user:
- throw new TAPException(error);
+ if (error instanceof Error)
+ throw (Error)error;
+ else
+ throw new TAPException(error);
}
}else
service.getLogger().logTAP(LogLevel.INFO, this, "SYNC_END", "The synchronous job " + ID + " successfully ended.", null);
@@ -340,10 +343,13 @@ public class TAPSyncJob {
// Log the end of the job:
if (e instanceof InterruptedException)
// Abortion:
- executor.getLogger().logThread(LogLevel.INFO, this, "END", "Synchronous thread \"" + getId() + "\" cancelled.", null);
+ executor.getLogger().logThread(LogLevel.INFO, this, "END", "Synchronous thread \"" + ID + "\" cancelled.", null);
+ else if (e instanceof Error)
+ // GRAVE error:
+ executor.getLogger().logThread(LogLevel.FATAL, this, "END", "Synchronous thread \"" + ID + "\" ended with a FATAL error.", exception);
else
// Error:
- executor.getLogger().logThread(LogLevel.ERROR, this, "END", "Synchronous thread \"" + getId() + "\" ended with an error.", exception);
+ executor.getLogger().logThread(LogLevel.ERROR, this, "END", "Synchronous thread \"" + ID + "\" ended with an error.", exception);
}
}
diff --git a/src/tap/db/JDBCConnection.java b/src/tap/db/JDBCConnection.java
index f3393e3..72e87d4 100644
--- a/src/tap/db/JDBCConnection.java
+++ b/src/tap/db/JDBCConnection.java
@@ -1481,9 +1481,10 @@ public class JDBCConnection implements DBConnection {
DatabaseMetaData dbMeta = connection.getMetaData();
// 1. Create the upload schema, if it does not already exist:
- if (!isSchemaExisting(tableDef.getDBSchemaName(), dbMeta))
+ if (!isSchemaExisting(tableDef.getDBSchemaName(), dbMeta)){
stmt.executeUpdate("CREATE SCHEMA " + translator.getQualifiedSchemaName(tableDef) + ";");
-
+ logger.logDB(LogLevel.INFO, this, "SCHEMA_CREATED", "Schema \"" + tableDef.getADQLSchemaName() + "\" (in DB: " + translator.getQualifiedSchemaName(tableDef) + ") created.", null);
+ }
// 1bis. Ensure the table does not already exist and if it is the case, throw an understandable exception:
else if (isTableExisting(tableDef.getDBSchemaName(), tableDef.getDBName(), dbMeta)){
DBException de = new DBException("Impossible to create the user uploaded table in the database: " + translator.getQualifiedTableName(tableDef) + "! This table already exists.");
@@ -1516,6 +1517,9 @@ public class JDBCConnection implements DBConnection {
// Commit the transaction:
commit();
+ // Log the end:
+ logger.logDB(LogLevel.INFO, this, "TABLE_CREATED", "Table \"" + tableDef.getADQLName() + "\" (in DB: " + translator.getQualifiedTableName(tableDef) + ") created.", null);
+
return true;
}catch(SQLException se){
@@ -1633,6 +1637,12 @@ public class JDBCConnection implements DBConnection {
stmt = connection.createStatement();
int cnt = stmt.executeUpdate("DROP TABLE " + translator.getQualifiedTableName(tableDef) + ";");
+ // Log the end:
+ if (cnt == 0)
+ logger.logDB(LogLevel.INFO, this, "TABLE_DROPPED", "Table \"" + tableDef.getADQLName() + "\" (in DB: " + translator.getQualifiedTableName(tableDef) + ") dropped.", null);
+ else
+ logger.logDB(LogLevel.ERROR, this, "TABLE_DROPPED", "Table \"" + tableDef.getADQLName() + "\" (in DB: " + translator.getQualifiedTableName(tableDef) + ") NOT dropped.", null);
+
// Ensure the update is successful:
return (cnt == 0);
diff --git a/src/tap/error/DefaultTAPErrorWriter.java b/src/tap/error/DefaultTAPErrorWriter.java
index e6e7256..064d778 100644
--- a/src/tap/error/DefaultTAPErrorWriter.java
+++ b/src/tap/error/DefaultTAPErrorWriter.java
@@ -36,7 +36,6 @@ import uws.job.ErrorType;
import uws.job.user.JobOwner;
import uws.service.error.DefaultUWSErrorWriter;
import uws.service.error.ServiceErrorWriter;
-import uws.service.log.UWSLog.LogLevel;
/**
* <p>Default implementation of {@link ServiceErrorWriter} for a TAP service.</p>
@@ -109,12 +108,9 @@ public class DefaultTAPErrorWriter implements ServiceErrorWriter {
writeError(t.getMessage(), type, httpErrorCode, response, request, reqID, user, action);
}
// Otherwise, log it and write a message to the user:
- else{
- // log the error as GRAVE/FATAL (because unexpected/unmanaged):
- logger.logTAP(LogLevel.FATAL, null, null, "[REQUEST N°" + reqID + "] " + t.getMessage(), t);
+ else
// write a message to the user:
- writeError("INTERNAL SERVER ERROR! Sorry, this error is unexpected and no explaination can be provided for the moment. Details about this error have been reported in the service log files ; you should try again your request later or notify the administrator(s) by yourself (with the following REQ_ID).", ErrorType.FATAL, UWSException.INTERNAL_SERVER_ERROR, response, request, reqID, user, action);
- }
+ writeError("INTERNAL SERVER ERROR! Sorry, this error is grave and unexpected. No explaination can be provided for the moment. Details about this error have been reported in the service log files ; you should try again your request later or notify the administrator(s) by yourself (with the following REQ_ID).", ErrorType.FATAL, UWSException.INTERNAL_SERVER_ERROR, response, request, reqID, user, action);
}
@Override
diff --git a/src/tap/log/TAPLog.java b/src/tap/log/TAPLog.java
index 40a9c71..2e9118f 100644
--- a/src/tap/log/TAPLog.java
+++ b/src/tap/log/TAPLog.java
@@ -79,7 +79,10 @@ public interface TAPLog extends UWSLog {
* <li>SYNC_INIT (with "obj" as an instance of {@link TAPParameters})</li>
* <li>ASYNC_INIT (with a NULL "obj")</li>
* <li>SYNC_START (with "obj" as an instance of {@link TAPSyncJob})</li>
- * <li>UPLOAD (with "obj" as an instance of {@link TAPExecutionReport})</li>
+ * <li>UPLOADING (with "obj" as an instance of {@link TAPExecutionReport})</li>
+ * <li>PARSING (with "obj" as an instance of {@link TAPExecutionReport})</li>
+ * <li>EXECUTING (with "obj" as an instance of {@link TAPExecutionReport})</li>
+ * <li>WRITING_RESULT (with "obj" as an instance of {@link TAPExecutionReport})</li>
* <li>FORMAT (with "obj" as an instance of {@link TAPExecutionReport})</li>
* <li>START_STEP (with "obj" as an instance of {@link TAPExecutionReport})</li>
* <li>END_EXEC (with "obj" as an instance of {@link TAPExecutionReport})</li>
diff --git a/src/tap/resource/Sync.java b/src/tap/resource/Sync.java
index 460b009..b83fc07 100644
--- a/src/tap/resource/Sync.java
+++ b/src/tap/resource/Sync.java
@@ -115,7 +115,7 @@ public class Sync implements TAPResource {
return true;
}catch(TAPException te){
throw te;
- }catch(Throwable t){
+ }catch(Exception t){
service.getLogger().logTAP(LogLevel.FATAL, params, "SYNC_INIT", "Unexpected error while executing the given ADQL query!", t);
throw new TAPException("Unexpected error while executing the given ADQL query!");
}
diff --git a/src/uws/job/JobThread.java b/src/uws/job/JobThread.java
index 1e979db..8f8a4af 100644
--- a/src/uws/job/JobThread.java
+++ b/src/uws/job/JobThread.java
@@ -391,7 +391,9 @@ public abstract class JobThread extends Thread {
}catch(Throwable t){
// Build the error:
- if (t.getMessage() == null || t.getMessage().trim().isEmpty())
+ if (t instanceof Error)
+ lastError = new UWSException(UWSException.INTERNAL_SERVER_ERROR, t, "A FATAL DEEP ERROR OCCURED WHILE EXECUTING THIS QUERY! This error is reported in the service logs.", ErrorType.FATAL);
+ else if (t.getMessage() == null || t.getMessage().trim().isEmpty())
lastError = new UWSException(UWSException.INTERNAL_SERVER_ERROR, t.getClass().getName(), ErrorType.FATAL);
else
lastError = new UWSException(UWSException.INTERNAL_SERVER_ERROR, t, ErrorType.FATAL);
@@ -402,18 +404,19 @@ public abstract class JobThread extends Thread {
// Publish the error if any has occurred:
if (lastError != null){
// Log the error:
- logger.logThread(LogLevel.ERROR, this, "END", "Thread \"" + getId() + "\" ended with an error.", lastError);
+ LogLevel logLevel = (lastError.getCause() != null && lastError.getCause() instanceof Error) ? LogLevel.FATAL : LogLevel.ERROR;
+ logger.logThread(logLevel, this, "END", "Thread \"" + getId() + "\" ended with an error.", lastError);
// Set the error into the job:
try{
setError(lastError);
}catch(UWSException ue){
try{
- logger.logThread(LogLevel.ERROR, this, "SET_ERROR", "[1st Attempt] Problem in JobThread.setError(UWSException), while setting the execution error of the job " + job.getJobId() + ". A last attempt will be done.", ue);
+ logger.logThread(logLevel, this, "SET_ERROR", "[1st Attempt] Problem in JobThread.setError(UWSException), while setting the execution error of the job " + job.getJobId() + ". A last attempt will be done.", ue);
setError(new ErrorSummary((lastError.getCause() != null) ? lastError.getCause().getMessage() : lastError.getMessage(), lastError.getUWSErrorType()));
}catch(UWSException ue2){
- logger.logThread(LogLevel.ERROR, this, "SET_ERROR", "[2nd and last Attempt] Problem in JobThread.setError(ErrorSummary), while setting the execution error of the job " + job.getJobId() + ". This error can not be reported to the user, but it will be reported in the log in the JOB context.", ue2);
+ logger.logThread(logLevel, this, "SET_ERROR", "[2nd and last Attempt] Problem in JobThread.setError(ErrorSummary), while setting the execution error of the job " + job.getJobId() + ". This error can not be reported to the user, but it will be reported in the log in the JOB context.", ue2);
// Note: no need of a level 3: if the second attempt fails, it means the job is in a wrong phase and no error summary can never be set ; further attempt won't change anything!
- logger.logJob(LogLevel.ERROR, job, "EXECUTING", "An error has interrupted the execution of the job \"" + job.getJobId() + "\". Here is its summary: " + lastError.getMessage(), lastError);
+ logger.logJob(logLevel, job, "EXECUTING", "An error has interrupted the execution of the job \"" + job.getJobId() + "\". Here is its summary: " + lastError.getMessage(), lastError);
}
}
}else
--
GitLab