add logging for some PSS actions

add NSI forced end event
esnet · Mar 6, 2019 · 062aa80 · 062aa80
1 parent 6b02af0
commit 062aa80
Show file tree

Hide file tree

Showing 7 changed files with 83 additions and 21 deletions.
diff --git a/backend/src/main/java/net/es/oscars/app/util/ThreadConfig.java b/backend/src/main/java/net/es/oscars/app/util/ThreadConfig.java
@@ -0,0 +1,21 @@
+package net.es.oscars.app.util;
+
+import org.springframework.context.annotation.Bean;
+import org.springframework.context.annotation.Configuration;
+import org.springframework.core.task.TaskExecutor;
+import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
+
+@Configuration
+public class ThreadConfig {
+
+    @Bean
+    public TaskExecutor threadPoolTaskExecutor() {
+        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
+        executor.setCorePoolSize(4);
+        executor.setMaxPoolSize(4);
+        executor.setThreadNamePrefix("default_task_executor_thread");
+        executor.initialize();
+        return executor;
+    }
+
+}
diff --git a/backend/src/main/java/net/es/oscars/nsi/svc/NsiService.java b/backend/src/main/java/net/es/oscars/nsi/svc/NsiService.java
@@ -48,6 +48,7 @@
 import org.apache.commons.lang3.tuple.Pair;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.beans.factory.annotation.Value;
+import org.springframework.core.task.TaskExecutor;
 import org.springframework.stereotype.Component;
 import org.springframework.transaction.annotation.Transactional;
 
@@ -121,6 +122,9 @@ public class NsiService {
     @Autowired
     private PSSAdapter pssAdapter;
 
+    @Autowired
+    private TaskExecutor taskExecutor;
+
     private static String nsBase = "http://schemas.ogf.org/nml/2013/05/base#";
     private static String nsDefs = "http://schemas.ogf.org/nsi/2013/12/services/definition";
     private static String nsEth = "http://schemas.ogf.org/nml/2012/10/ethernet";
@@ -129,7 +133,6 @@ public class NsiService {
 
     /* async operations */
     public void reserve(CommonHeaderType header, ReserveType rt, NsiMapping mapping) {
-
         Executors.newCachedThreadPool().submit(() -> {
             log.info("starting reserve task");
             try {
@@ -223,9 +226,9 @@ public void commit(CommonHeaderType header, NsiMapping mapping) {
     }
 
     public void abort(CommonHeaderType header, NsiMapping mapping) {
+        log.info("starting abort task for "+mapping.getNsiConnectionId());
 
         Executors.newCachedThreadPool().submit(() -> {
-            log.info("starting abort task");
             try {
                 Connection c = this.getOscarsConnection(mapping);
                 nsiStateEngine.abort(NsiEvent.ABORT_START, mapping);
@@ -251,9 +254,9 @@ public void abort(CommonHeaderType header, NsiMapping mapping) {
     }
 
     public void provision(CommonHeaderType header, NsiMapping mapping) {
+        log.info("starting provision task for "+mapping.getNsiConnectionId());
 
         Executors.newCachedThreadPool().submit(() -> {
-            log.info("starting provision task");
             try {
                 Connection c = this.getOscarsConnection(mapping);
                 if (!c.getPhase().equals(Phase.RESERVED)) {
@@ -288,13 +291,13 @@ public void provision(CommonHeaderType header, NsiMapping mapping) {
     }
 
     public void release(CommonHeaderType header, NsiMapping mapping) {
+        log.info("starting release task for "+mapping.getNsiConnectionId());
 
         Executors.newCachedThreadPool().submit(() -> {
-            log.info("starting release task");
             try {
                 Connection c = this.getOscarsConnection(mapping);
                 if (!c.getPhase().equals(Phase.RESERVED)) {
-                    log.error("cannot provision unless RESERVED");
+                    log.error("cannot release unless RESERVED");
                     return null;
                 }
 
@@ -336,9 +339,9 @@ public void release(CommonHeaderType header, NsiMapping mapping) {
     }
 
     public void terminate(CommonHeaderType header, NsiMapping mapping) {
+        log.info("starting terminate task for "+mapping.getNsiConnectionId());
 
         Executors.newCachedThreadPool().submit(() -> {
-            log.info("starting terminate task");
             try {
                 Connection c = this.getOscarsConnection(mapping);
                 // the cancel only needs to happen if we are not in FORCED_END or PASSED_END_TIME
@@ -371,17 +374,16 @@ public void terminate(CommonHeaderType header, NsiMapping mapping) {
     // currently unused
     // TODO: trigger this when REST API terminates connection
     // (& possibly other errors)
-    public void forcedEnd(CommonHeaderType header, NsiMapping mapping)
+    public void forcedEnd(NsiMapping mapping)
             throws InterruptedException {
+        log.info("starting forcedEnd task for "+mapping.getNsiConnectionId());
 
         Executors.newCachedThreadPool().submit(() -> {
-            log.info("starting forcedEnd task");
             try {
-                Connection c = this.getOscarsConnection(mapping);
                 nsiStateEngine.forcedEnd(mapping);
-                this.errorNotify(NsiEvent.FORCED_END, mapping, header);
+                this.errorNotify(NsiEvent.FORCED_END, mapping);
             } catch (NsiException ex) {
-                log.error("failed terminate, internal error");
+                log.error("failed forcedEnd, internal error");
                 log.error(ex.getMessage(), ex);
             } catch (RuntimeException ex) {
                 log.error("serious error", ex);
@@ -1025,10 +1027,25 @@ public static void checkStp(String stp) throws NsiException {
     /* SOAP calls to the client */
 
 
-    public void errorNotify(NsiEvent event, NsiMapping mapping, CommonHeaderType inHeader) throws ServiceException {
-        log.info("error notify (only used by forcedEnd)");
-        // TODO
-        throw new ServiceException("not implemented");
+    public void errorNotify(NsiEvent event, NsiMapping mapping) throws NsiException, ServiceException, DatatypeConfigurationException {
+        String nsaId = mapping.getNsaId();
+        if (!this.getRequesterNsa(nsaId).isPresent()) {
+            throw new NsiException("Unknown requester nsa id " + nsaId, NsiErrors.SEC_ERROR);
+        }
+        NsiRequesterNSA requesterNSA = this.getRequesterNsa(nsaId).get();
+        ConnectionRequesterPort port = clientUtil.createRequesterClient(requesterNSA);
+        String corrId = this.newCorrelationId();
+        Holder<CommonHeaderType> outHeader = this.makeClientHeader(nsaId, corrId);
+        ErrorEventType eet = new ErrorEventType();
+        eet.setOriginatingConnectionId(mapping.getNsiConnectionId());
+        eet.setOriginatingNSA(this.providerNsa);
+        ZonedDateTime zd = ZonedDateTime.ofInstant(Instant.now(), ZoneId.systemDefault());
+        GregorianCalendar c = GregorianCalendar.from(zd);
+        XMLGregorianCalendar xgc = DatatypeFactory.newInstance().newXMLGregorianCalendar(c);
+
+        eet.setTimeStamp(xgc);
+        eet.setEvent(EventEnumType.FORCED_END);
+        port.errorEvent(eet, outHeader);
 
     }
 

diff --git a/backend/src/main/java/net/es/oscars/pss/svc/PSSAdapter.java b/backend/src/main/java/net/es/oscars/pss/svc/PSSAdapter.java
@@ -84,7 +84,7 @@ public void generateConfig(Connection conn) throws PSSException {
     }
 
     public State build(Connection conn) throws PSSException {
-        log.info("setting up " + conn.getConnectionId());
+        log.info("building " + conn.getConnectionId());
         List<Command> commands = this.buildCommands(conn);
         List<CommandStatus> stable = this.getStableStatuses(commands);
         Instant now = Instant.now();
@@ -111,7 +111,7 @@ public State build(Connection conn) throws PSSException {
     }
 
     public State dismantle(Connection conn) throws PSSException {
-        log.info("tearing down " + conn.getConnectionId());
+        log.info("dismantling " + conn.getConnectionId());
         List<Command> commands = this.dismantleCommands(conn);
         List<CommandStatus> stable = this.getStableStatuses(commands);
         Instant now = Instant.now();

diff --git a/backend/src/main/java/net/es/oscars/resv/svc/ConnService.java b/backend/src/main/java/net/es/oscars/resv/svc/ConnService.java
@@ -391,6 +391,7 @@ public ConnChangeResult uncommit(Connection c) {
     public ConnChangeResult release(Connection c) {
         // if it is HELD or DESIGN, delete it
         if (c.getPhase().equals(Phase.HELD) || c.getPhase().equals(Phase.DESIGN)) {
+            log.debug("deleting HELD / DESIGN connection during release"+c.getConnectionId());
             connRepo.delete(c);
             connRepo.flush();
             return ConnChangeResult.builder()
@@ -408,14 +409,16 @@ public ConnChangeResult release(Connection c) {
         if (c.getPhase().equals(Phase.RESERVED)) {
             if (c.getReserved().getSchedule().getBeginning().isAfter(Instant.now())) {
                 // we haven't started yet; can delete without consequence
+                log.debug("deleting unstarted connection during release"+c.getConnectionId());
                 connRepo.delete(c);
                 return ConnChangeResult.builder()
                         .what(ConnChange.DELETED)
                         .when(Instant.now())
                         .build();
             }
             if (c.getState().equals(State.ACTIVE)) {
-                slack.sendMessage("Cancelling active reservation: " + c.getConnectionId());
+                slack.sendMessage("Cancelling active connection: " + c.getConnectionId());
+                log.debug("Releasing active connection: "+c.getConnectionId());
 
                 // need to dismantle first, that part relies on Reserved components
                 try {
@@ -429,7 +432,7 @@ public ConnChangeResult release(Connection c) {
                 }
 
             } else {
-                slack.sendMessage("Cancelling non-active reservation: " + c.getConnectionId());
+                slack.sendMessage("Cancelling non-active connection: " + c.getConnectionId());
             }
         }
 

diff --git a/backend/src/main/java/net/es/oscars/task/PssTask.java b/backend/src/main/java/net/es/oscars/task/PssTask.java
@@ -124,6 +124,7 @@ public void genConfigsBuildDismantle() {
 
                 for (Connection c : shouldBeBuilt) {
                     try {
+                        log.info("building connection " + c.getConnectionId());
                         State s = this.pssAdapter.build(c);
                         newStates.put(c.getConnectionId(), s);
                     } catch (PSSException ex) {
@@ -133,6 +134,7 @@ public void genConfigsBuildDismantle() {
                 }
                 for (Connection c : shouldBeDismantled) {
                     try {
+                        log.info("dismantling expired connection " + c.getConnectionId());
                         State s = this.pssAdapter.dismantle(c);
                         newStates.put(c.getConnectionId(), s);
                     } catch (PSSException ex) {

diff --git a/backend/src/main/java/net/es/oscars/task/TransitionStates.java b/backend/src/main/java/net/es/oscars/task/TransitionStates.java
@@ -88,7 +88,7 @@ public void processingLoop() {
                         }
 
                         if (c.getState().equals(State.ACTIVE)) {
-                            log.info(c.getConnectionId() + " : state is active, will not archive until dismantled");
+                            log.info(c.getConnectionId() + " : active; waiting for dismantle before archiving");
                         } else {
                             archiveThese.add(c);
                         }
@@ -106,9 +106,13 @@ public void processingLoop() {
                     return;
                 }
 
+                deleteThese.forEach(c -> {
+                    log.debug("Deleting "+c.getConnectionId());
+                });
                 connRepo.delete(deleteThese);
 
                 archiveThese.forEach(c -> {
+                    log.debug("Archiving "+c.getConnectionId());
                     c.setPhase(Phase.ARCHIVED);
                     c.setReserved(null);
                     connRepo.saveAndFlush(c);

diff --git a/backend/src/main/java/net/es/oscars/web/rest/ConnController.java b/backend/src/main/java/net/es/oscars/web/rest/ConnController.java
@@ -2,9 +2,12 @@
 
 import lombok.extern.slf4j.Slf4j;
 import net.es.oscars.app.Startup;
+import net.es.oscars.app.exc.NsiException;
 import net.es.oscars.app.exc.PCEException;
 import net.es.oscars.app.exc.PSSException;
 import net.es.oscars.app.exc.StartupException;
+import net.es.oscars.nsi.ent.NsiMapping;
+import net.es.oscars.nsi.svc.NsiService;
 import net.es.oscars.pss.ent.RouterCommandHistory;
 import net.es.oscars.resv.db.CommandHistoryRepository;
 import net.es.oscars.resv.db.ConnectionRepository;
@@ -39,6 +42,8 @@ public class ConnController {
 
     @Autowired
     private ConnService connSvc;
+    @Autowired
+    private NsiService nsiSvc;
 
     @ExceptionHandler(StartupException.class)
     @ResponseStatus(value = HttpStatus.SERVICE_UNAVAILABLE)
@@ -51,14 +56,14 @@ public void handleStartup(StartupException ex) {
     public void handleMiscException(ConnException ex) {
         log.warn("conn request error", ex);
     }
+
     @ExceptionHandler(NoSuchElementException.class)
     @ResponseStatus(value = HttpStatus.NOT_FOUND)
     public void handleResourceNotFoundException(NoSuchElementException ex) {
         log.warn("requested an item which did not exist");
     }
 
 
-
     @RequestMapping(value = "/protected/conn/generateId", method = RequestMethod.GET)
     public String generateConnectionId() throws StartupException {
         if (startup.isInStartup()) {
@@ -147,6 +152,16 @@ public ConnChangeResult release(@RequestBody String connectionId) throws Startup
         } else if (c.get().getPhase().equals(Phase.ARCHIVED)) {
             throw new ConnException("Cannot cancel ARCHIVED connection");
         } else {
+            try {
+                Optional<NsiMapping> om = nsiSvc.getMappingForOscarsId(c.get().getConnectionId());
+                if (om.isPresent()) {
+                    nsiSvc.forcedEnd(om.get());
+
+                }
+
+            } catch (NsiException | InterruptedException ex) {
+                log.error(ex.getMessage(),ex);
+            }
             return connSvc.release(c.get());
         }
     }