Skip to content

Commit

Permalink
improve defaults and logging
Browse files Browse the repository at this point in the history
Issue #210
  • Loading branch information
rsoika committed Jul 15, 2024
1 parent 531c6b9 commit fa2cb94
Show file tree
Hide file tree
Showing 4 changed files with 75 additions and 53 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -39,23 +39,6 @@
import java.util.logging.Level;
import java.util.logging.Logger;

import jakarta.ejb.EJB;
import jakarta.enterprise.context.RequestScoped;
import jakarta.inject.Inject;
import jakarta.inject.Named;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.ws.rs.Consumes;
import jakarta.ws.rs.Encoded;
import jakarta.ws.rs.GET;
import jakarta.ws.rs.POST;
import jakarta.ws.rs.Path;
import jakarta.ws.rs.PathParam;
import jakarta.ws.rs.Produces;
import jakarta.ws.rs.core.Context;
import jakarta.ws.rs.core.MediaType;
import jakarta.ws.rs.core.Response;
import jakarta.ws.rs.core.UriInfo;

import org.eclipse.microprofile.config.inject.ConfigProperty;
import org.imixs.archive.core.SnapshotException;
import org.imixs.archive.core.SnapshotService;
Expand All @@ -74,6 +57,23 @@
import org.imixs.workflow.xml.XMLDocument;
import org.imixs.workflow.xml.XMLDocumentAdapter;

import jakarta.ejb.EJB;
import jakarta.enterprise.context.RequestScoped;
import jakarta.inject.Inject;
import jakarta.inject.Named;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.ws.rs.Consumes;
import jakarta.ws.rs.Encoded;
import jakarta.ws.rs.GET;
import jakarta.ws.rs.POST;
import jakarta.ws.rs.Path;
import jakarta.ws.rs.PathParam;
import jakarta.ws.rs.Produces;
import jakarta.ws.rs.core.Context;
import jakarta.ws.rs.core.MediaType;
import jakarta.ws.rs.core.Response;
import jakarta.ws.rs.core.UriInfo;

/**
* The SnapshotRestService provides a Rest API to access the snapshot data.
* <p>
Expand All @@ -97,10 +97,10 @@
public class SnapshotRestService implements Serializable {

private static final long serialVersionUID = 1L;

@Inject
@ConfigProperty(name = SnapshotService.ARCHIVE_SERVICE_ENDPOINT)
Optional<String> archiveServiceEndpoint;
Optional<String> archiveServiceEndpoint;

@jakarta.ws.rs.core.Context
private HttpServletRequest servletRequest;
Expand Down Expand Up @@ -164,7 +164,7 @@ public Response getWorkItemFile(@PathParam("uniqueid") String uniqueid, @PathPar
long l = System.currentTimeMillis();
byte[] fileContent;
fileContent = archiveClientService.loadFileFromArchive(fileData);
if (fileContent != null && fileContent.length>0) {
if (fileContent != null && fileContent.length > 0) {
Response.ResponseBuilder builder = Response.ok(fileContent, fileData.getContentType());
// found -> return directy.
if (debug) {
Expand All @@ -176,7 +176,7 @@ public Response getWorkItemFile(@PathParam("uniqueid") String uniqueid, @PathPar
// Critical situation!
// The file data is not available in the cassandra storage
// We print a error message and try to load the file from the local snapshot
logger.severe("Failed to load '" + file+"' form imixs-archive - fallback to local snapshot...");
logger.severe("Failed to load '" + file + "' form imixs-archive - fallback to local snapshot...");
}

} catch (RestAPIException e) {
Expand Down Expand Up @@ -220,7 +220,7 @@ public XMLDataCollection getDocumentsBySyncPoint(@PathParam("syncpoint") long lS
query += " WHERE document.modified > '" + isoFormat.format(syncpoint) + "'";
query += " AND document.type LIKE '" + SnapshotService.TYPE_PRAFIX + "%' ";
query += " ORDER BY document.modified ASC";
logger.finest("......QUERY=" + query);
logger.info("......QUERY-1=" + query);

result = documentService.getDocumentsByQuery(query, 1);
// do we found new data?
Expand All @@ -245,20 +245,20 @@ public XMLDataCollection getDocumentsBySyncPoint(@PathParam("syncpoint") long lS
query = "SELECT document FROM Document AS document ";
query += " WHERE document.modified = '" + isoFormat.format(syncpoint) + "'";
query += " AND document.type LIKE '" + SnapshotService.TYPE_PRAFIX + "%' ";
logger.finest("......QUERY=" + query);
logger.info("......QUERY-2=" + query);
result = documentService.getDocumentsByQuery(query, 16 + 1);

// if more than 16 syncpoints with the same modifed time stamp exists we have in
// deed a problem
// if more than 16 syncPoints with the same modified time stamp exists we have
// in deed a problem
if (result.size() > 16) {
throw new SnapshotException(SnapshotException.INVALID_DATA,
"more than 16 document entites are found with the same modified timestamp. "
+ "We assumed that this case is impossible. Sync is not possible.");
"more than 16 document entities found with the same modified timestamp. "
+ "We assumed that this case is impossible. Sync is not possible and will be terminated...");
}
if (result.size() == 0) {
throw new SnapshotException(SnapshotException.INVALID_DATA,
"failed to load snapshot by modified timestamp. "
+ "We assumed that this case is impossible. Sync is not possible.");
+ "We assumed that this case is impossible. Sync is not possible and will be terminated...");
}

return XMLDataCollectionAdapter.getDataCollection(result);
Expand Down Expand Up @@ -333,8 +333,8 @@ public Response postSnapshot(XMLDocument xmlworkitem) {
// Explicit write archive event log entry to update ArchiveService...
if (archiveServiceEndpoint.isPresent() && !archiveServiceEndpoint.get().isEmpty()) {
eventLogService.createEvent(SnapshotService.EVENTLOG_TOPIC_ADD, snapshotID);
}
}

logger.info("......document '" + originUnqiueID + "' restored.");
return Response.ok(XMLDataCollectionAdapter.getDataCollection(document), MediaType.APPLICATION_XML).build();

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,13 @@
import java.util.Optional;
import java.util.logging.Logger;

import org.eclipse.microprofile.config.inject.ConfigProperty;
import org.imixs.melman.BasicAuthenticator;
import org.imixs.melman.DocumentClient;
import org.imixs.melman.EventLogClient;
import org.imixs.melman.FormAuthenticator;
import org.imixs.melman.RestAPIException;

import jakarta.annotation.PostConstruct;
import jakarta.annotation.Resource;
import jakarta.annotation.security.DeclareRoles;
Expand All @@ -17,13 +24,6 @@
import jakarta.ws.rs.NotFoundException;
import jakarta.ws.rs.client.ClientRequestFilter;

import org.eclipse.microprofile.config.inject.ConfigProperty;
import org.imixs.melman.BasicAuthenticator;
import org.imixs.melman.DocumentClient;
import org.imixs.melman.EventLogClient;
import org.imixs.melman.FormAuthenticator;
import org.imixs.melman.RestAPIException;

/**
* The SyncScheduler starts a TimerService to pull new snapshot events from the
* workflow instance and push the snapshot data into the cassandra cluster
Expand All @@ -35,14 +35,13 @@
@Startup
@Singleton
@LocalBean
//@ConcurrencyManagement(ConcurrencyManagementType.BEAN)
@DeclareRoles({ "org.imixs.ACCESSLEVEL.MANAGERACCESS" })
@RunAs("org.imixs.ACCESSLEVEL.MANAGERACCESS")
public class SyncScheduler {

// timeout interval in ms
@Inject
@ConfigProperty(name = ImixsArchiveApp.WORKFLOW_SYNC_INTERVAL, defaultValue = "1000")
@ConfigProperty(name = ImixsArchiveApp.WORKFLOW_SYNC_INTERVAL, defaultValue = "5000")
long interval;

@Inject
Expand Down Expand Up @@ -108,29 +107,36 @@ public void run(Timer timer) {
EventLogClient eventLogClient = null;
ClientRequestFilter authenticator = null;

logger.fine("--- run timeout.... timerinfo= " + timer.getInfo());
try {
// Test the authentication method and create a corresponding Authenticator
if ("Form".equalsIgnoreCase(workflowServiceAuthMethod.get())) {
// test if a JSESSIONID exists?
String jSessionID = (String) timer.getInfo();
if (jSessionID == null || jSessionID.isEmpty()) {
logger.fine("--- jSessionID is empty - need new login....");
// no - we need to login first and store the JSESSIONID in a new timer object...
// create a FormAuthenticator
FormAuthenticator formAuth = new FormAuthenticator(workflowServiceEndpoint.get(),
workflowServiceUser.get(), workflowServicePassword.get());
// Authentication successful - do we have a JSESSIONID?
String jsessionID = formAuth.getJsessionID();
if (jsessionID != null && !jsessionID.isEmpty()) {
logger.fine("--- reinitialze timer with new jSessionID : " + jsessionID + " and interval="
+ interval);
// yes - terminate existing timer and create a new one with the JSESSIONID

timer.cancel();
final TimerConfig timerConfig = new TimerConfig();
timerConfig.setInfo(jsessionID);
timerConfig.setPersistent(false);
timerService.createIntervalTimer(interval, interval, timerConfig);
logger.info("successful connected: " + workflowServiceEndpoint.get());
logger.fine("---created new timer");
logger.info("successful connected: " + workflowServiceEndpoint.get() + " new Timer created...");
return;
}
} else {
logger.fine("--- reuse jSessionID " + jSessionID + " for login....");
// we have already a jsessionCooke Data object - so create a new
// FormAuthenticator form the JSESSIONID
FormAuthenticator formAuth = new FormAuthenticator(workflowServiceEndpoint.get(), jSessionID);
Expand All @@ -150,11 +156,12 @@ public void run(Timer timer) {
documentClient.registerClientRequestFilter(authenticator);
eventLogClient = new EventLogClient(workflowServiceEndpoint.get());
eventLogClient.registerClientRequestFilter(authenticator);

logger.fine("--- process event log....");
// release dead locks...
archiveSyncService.releaseDeadLocks(eventLogClient);
// process the eventLog...
archiveSyncService.processEventLog(eventLogClient, documentClient);
logger.fine("--- process event log completed.");
} else {
// no valid Authenticator!
logger.warning("unable to connect: " + workflowServiceEndpoint);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,13 +5,6 @@
import java.util.logging.Level;
import java.util.logging.Logger;

import jakarta.ejb.EJBException;
import jakarta.ejb.LocalBean;
import jakarta.ejb.Stateless;
import jakarta.ejb.TransactionAttribute;
import jakarta.ejb.TransactionAttributeType;
import jakarta.inject.Inject;

import org.eclipse.microprofile.config.inject.ConfigProperty;
import org.imixs.archive.service.cassandra.DataService;
import org.imixs.melman.DocumentClient;
Expand All @@ -20,6 +13,13 @@
import org.imixs.workflow.ItemCollection;
import org.imixs.workflow.exceptions.InvalidAccessException;

import jakarta.ejb.EJBException;
import jakarta.ejb.LocalBean;
import jakarta.ejb.Stateless;
import jakarta.ejb.TransactionAttribute;
import jakarta.ejb.TransactionAttributeType;
import jakarta.inject.Inject;

/**
* The SyncService pulls a Snapshot into an Apache Cassandra archive. The
* service uses an asynchronous mechanism based on the Imixs EventLog.
Expand Down Expand Up @@ -81,6 +81,8 @@ public void processEventLog(EventLogClient eventLogClient, DocumentClient docume
String id = null;
String ref = null;
ItemCollection snapshot = null;
long count = 0;
long duration = System.currentTimeMillis();

if (documentClient == null || eventLogClient == null) {
// no client object
Expand Down Expand Up @@ -121,6 +123,7 @@ public void processEventLog(EventLogClient eventLogClient, DocumentClient docume
eventLogClient.createEventLogEntry(ImixsArchiveApp.EVENTLOG_TOPIC_BACKUP, ref, null);
}
}
count++;
} catch (InvalidAccessException | EJBException | ArchiveException e) {
// we also catch EJBExceptions here because we do not want to cancel the
// ManagedScheduledExecutorService
Expand All @@ -131,6 +134,7 @@ public void processEventLog(EventLogClient eventLogClient, DocumentClient docume
// eventLogService.removeEvent(eventLogEntry.getId());
}
}
logger.info("Processed " + count + " snapshot events in " + (System.currentTimeMillis() - duration) + "ms");

}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -223,7 +223,7 @@ void onTimeout(jakarta.ejb.Timer timer) throws Exception {
totalSize = metaData.getItemValueLong(ITEM_SYNCSIZE);

// ...start sync
logger.info("...start syncronizing at syncpoint " + new Date(syncPoint) + "...");
logger.info("...start synchronizing at syncPoint " + new Date(syncPoint) + "...");

// Daylight Saving Time Correction
// issue #53
Expand All @@ -235,14 +235,16 @@ void onTimeout(jakarta.ejb.Timer timer) throws Exception {
}

while (true) {

long lReadTime = System.currentTimeMillis();
long lTotalTime = System.currentTimeMillis();
XMLDataCollection xmlDataCollection = remoteAPIService.readSyncData(syncPoint);

if (xmlDataCollection != null) {
logger.info("...found " + xmlDataCollection.getDocument().length + " snapshots at syncpoint "
+ new Date(syncPoint) + " in " + (System.currentTimeMillis() - lReadTime) + "ms");
List<XMLDocument> snapshotList = Arrays.asList(xmlDataCollection.getDocument());

for (XMLDocument xmlDocument : snapshotList) {

long lSyncTime = System.currentTimeMillis();
ItemCollection snapshot = XMLDocumentAdapter.putDocument(xmlDocument);

// update snypoint
Expand All @@ -265,12 +267,17 @@ void onTimeout(jakarta.ejb.Timer timer) throws Exception {
+ e.getMessage());
// we continue....
}
logger.info(
"...snapshot '" + snapshot.getUniqueID() + "' written in "
+ (System.currentTimeMillis() - lSyncTime) + "ms");

} else {
// This is because in case of a restore, the same snapshot takes a new $modified
// item. And we do not want to re-import the snapshot in the next sync cycle.
// see issue #40
logger.fine("...snapshot '" + snapshot.getUniqueID() + "' already exits....");
logger.info(
"...snapshot '" + snapshot.getUniqueID() + "' already exits - verification took "
+ (System.currentTimeMillis() - lSyncTime) + "ms");
}

syncread++;
Expand All @@ -283,6 +290,10 @@ void onTimeout(jakarta.ejb.Timer timer) throws Exception {
lastUniqueID = "0";
dataService.saveMetadata(metaData);

logger.info(
"...snapshot '" + snapshot.getUniqueID() + "' synchronized in "
+ (System.currentTimeMillis() - lTotalTime) + "ms");

if (syncStatusHandler.getStatus() == ResyncStatusHandler.STAUS_CANCELED) {
break;
}
Expand Down

0 comments on commit fa2cb94

Please sign in to comment.