BandwidthOnDemand / nsi-safnari

A NSI Aggregator Coordinator
BSD 3-Clause "New" or "Revised" License
4 stars 0 forks source link

Error message in response to a request to a child NSA not properly processed. #13

Closed jmacauley closed 8 years ago

jmacauley commented 10 years ago

Used nsi-requester on ESnet to issue a connection request to ESnet nsi-safnari instance with the following endpoints:

<sourceSTP>urn:ogf:network:geant.net:2013:topology:manlan?vlan=3400</sourceSTP>
<destSTP>urn:ogf:network:geant.net:2013:topology:bi-geant-surfnet1?vlan=3400</destSTP>

Endpoints were properly resolved and connection request was issued to AutoBAHN NSA. Reservation was successful, and service was properly transitioned through lifecycle. Issued terminate request to AutoBAHN NSA immediately after endTime. AutoBAHN ACK'ed the request. Up to this point all messages within the context of this reservation request were properly displayed in the detailed connection information of the nsi-safnari web GUI. In addition, all messages within the nsi-requester's context were properly displayed.

AutoBAHN responded with an error message indicating that the terminate request was not valid for the current state of the connection (a bug). The error message was properly logged by nsi-safnari, however, the error message was not displayed in nsi-safnari web GUI, and the error message was not propagated northbound to the RA (nsi-requester).

Here are the logs for the sequence of events:

2014-07-09 14:47:22,971 DEBUG application play-akka.actor.default-dispatcher-521   - received SOAP message /nsi-v2/ConnectionServiceProvider from 127.0.0.1 with content-type Some(text/xml) <soapenv:Envelope xmlns:xs="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:gns="http://nordu.net/namespaces/2013/12/gnsbod" xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:type="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:head="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/">
      <soapenv:Header>
        <head:nsiHeader>
      <protocolVersion>application/vnd.ogf.nsi.cs.v2.provider+soap</protocolVersion>
      <correlationId>urn:uuid:39cfb694-6eff-44ed-87b7-a97af963dd7b</correlationId>
      <requesterNSA>urn:ogf:network:es.net:2013:nsa:nsi-requester</requesterNSA>
      <providerNSA>urn:ogf:network:es.net:2013:nsa:nsi-aggr-west</providerNSA>
      <replyTo>https://nsi-aggr-west.es.net/requester/reply</replyTo>
      <sessionSecurityAttr>

            <saml:Attribute Name="token">
                  <saml:AttributeValue xsi:type="xs:string">4e9d11a2-af63-45c5-a4f8-bb63c9f43a87</saml:AttributeValue>
                </saml:Attribute>
          </sessionSecurityAttr>

    </head:nsiHeader>
      </soapenv:Header>
      <soapenv:Body>
        <type:terminate>
      <connectionId>ba5d393a-8cfd-4d3d-9eca-cedf2f65428e</connectionId>
    </type:terminate>
      </soapenv:Body>
    </soapenv:Envelope> -
2014-07-09 14:47:22,974 DEBUG application play-akka.actor.default-dispatcher-521   - SOAP message parse result Success([#document: null]) -
2014-07-09 14:47:22,977 DEBUG application play-internal-execution-context-1   - Received (/nsi-v2/ConnectionServiceProvider): Success(NsiProviderMessage(NsiHeaders(urn:uuid:39cfb694-6eff-44ed-87b7-a97af963dd7b,urn:ogf:network:es.net:2013:nsa:nsi-requester,urn:ogf:network:es.net:2013:nsa:nsi-aggr-west,Some(https://nsi-aggr-west.es.net/requester/reply),application/vnd.ogf.nsi.cs.v2.provider+soap,List(org.ogf.schemas.nsi._2013._12.framework.headers.SessionSecurityAttrType@3a414ac4[attributeOrEncryptedAttribute={oasis.names.tc.saml._2_0.assertion.AttributeType@49b649ed[attributeValue={4e9d11a2-af63-45c5-a4f8-bb63c9f43a87}, name=token, nameFormat=<null>, friendlyName=<null>]}, type=<null>, name=<null>]),List()),Terminate(ba5d393a-8cfd-4d3d-9eca-cedf2f65428e))) -
2014-07-09 14:47:22,979 DEBUG application application-akka.actor.default-dispatcher-453   - state change from PASSED_END_TIME to TERMINATING -
2014-07-09 14:47:23,069 DEBUG application application-akka.actor.default-dispatcher-453   - Scheduling Delete for execution after 86399911 milliseconds -
2014-07-09 14:47:23,074 DEBUG application play-akka.actor.default-dispatcher-521   - Ack 127.0.0.1 with Success(<?xml version="1.0" encoding="UTF-8" standalone="no"?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Header><ns7:nsiHeader xmlns:ns2="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns3="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns4="http://www.w3.org/2001/04/xmlenc#" xmlns:ns5="http://www.w3.org/2000/09/xmldsig#" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns8="http://schemas.ogf.org/nsi/2013/12/services/point2point" xmlns:ns9="http://nordu.net/namespaces/2013/12/gnsbod"><protocolVersion>application/vnd.ogf.nsi.cs.v2.provider+soap</protocolVersion><correlationId>urn:uuid:39cfb694-6eff-44ed-87b7-a97af963dd7b</correlationId><requesterNSA>urn:ogf:network:es.net:2013:nsa:nsi-requester</requesterNSA><providerNSA>urn:ogf:network:es.net:2013:nsa:nsi-aggr-west</providerNSA></ns7:nsiHeader></soapenv:Header><soapenv:Body><ns2:acknowledgment xmlns:ns2="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns3="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns4="http://www.w3.org/2001/04/xmlenc#" xmlns:ns5="http://www.w3.org/2000/09/xmldsig#" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns8="http://schemas.ogf.org/nsi/2013/12/services/point2point" xmlns:ns9="http://nordu.net/namespaces/2013/12/gnsbod"/></soapenv:Body></soapenv:Envelope>) -
2014-07-09 14:47:23,075 DEBUG application application-akka.actor.default-dispatcher-454   - Sending provider urn:ogf:network:geant.net:2013:nsa at https://beta-bodv3.geant.net:8091/nsi/ConnectionProvider the SOAP message: Success(<?xml version="1.0" encoding="UTF-8" standalone="no"?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Header><ns7:nsiHeader xmlns:ns2="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns3="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns4="http://www.w3.org/2001/04/xmlenc#" xmlns:ns5="http://www.w3.org/2000/09/xmldsig#" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns8="http://schemas.ogf.org/nsi/2013/12/services/point2point" xmlns:ns9="http://nordu.net/namespaces/2013/12/gnsbod"><protocolVersion>application/vnd.ogf.nsi.cs.v2.provider+soap</protocolVersion><correlationId>urn:uuid:fa5cc71c-2067-4c2a-974c-9c6019b2b306</correlationId><requesterNSA>urn:ogf:network:es.net:2013:nsa:nsi-aggr-west</requesterNSA><providerNSA>urn:ogf:network:geant.net:2013:nsa</providerNSA><replyTo>https://nsi-aggr-west.es.net/nsi-v2/ConnectionServiceRequester</replyTo><sessionSecurityAttr><ns3:Attribute Name="token"><ns3:AttributeValue xmlns:xs="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">4e9d11a2-af63-45c5-a4f8-bb63c9f43a87</ns3:AttributeValue></ns3:Attribute></sessionSecurityAttr></ns7:nsiHeader></soapenv:Header><soapenv:Body><ns2:terminate xmlns:ns2="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns3="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns4="http://www.w3.org/2001/04/xmlenc#" xmlns:ns5="http://www.w3.org/2000/09/xmldsig#" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns8="http://schemas.ogf.org/nsi/2013/12/services/point2point" xmlns:ns9="http://nordu.net/namespaces/2013/12/gnsbod"><connectionId>urn:uuid:fb2c4db9-0319-4160-9a5f-147284473560</connectionId></ns2:terminate></soapenv:Body></soapenv:Envelope>) -
2014-07-09 14:47:24,039 DEBUG application play-akka.actor.default-dispatcher-521   - Parsing SOAP ack (200) from urn:ogf:network:geant.net:2013:nsa at https://beta-bodv3.geant.net:8091/nsi/ConnectionProvider: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Header><ns6:nsiHeader xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns5="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns4="http://www.w3.org/2000/09/xmldsig#" xmlns:ns3="http://www.w3.org/2001/04/xmlenc#" xmlns:ns2="urn:oasis:names:tc:SAML:2.0:assertion"><protocolVersion>application/vnd.ogf.nsi.cs.v2.provider+soap</protocolVersion><correlationId>urn:uuid:fa5cc71c-2067-4c2a-974c-9c6019b2b306</correlationId><requesterNSA>urn:ogf:network:es.net:2013:nsa:nsi-aggr-west</requesterNSA><providerNSA>urn:ogf:network:geant.net:2013:nsa</providerNSA></ns6:nsiHeader></soap:Header><soap:Body><ns5:acknowledgment xmlns:ns2="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns3="http://www.w3.org/2001/04/xmlenc#" xmlns:ns4="http://www.w3.org/2000/09/xmldsig#" xmlns:ns5="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/types"/></soap:Body></soap:Envelope> -
2014-07-09 14:47:24,044 DEBUG application play-akka.actor.default-dispatcher-521   - Received ack from urn:ogf:network:geant.net:2013:nsa at https://beta-bodv3.geant.net:8091/nsi/ConnectionProvider: NsiProviderMessage(NsiHeaders(urn:uuid:fa5cc71c-2067-4c2a-974c-9c6019b2b306,urn:ogf:network:es.net:2013:nsa:nsi-aggr-west,urn:ogf:network:geant.net:2013:nsa,None,application/vnd.ogf.nsi.cs.v2.provider+soap,List(),List()),GenericAck()) -
2014-07-09 14:47:24,045 DEBUG application application-akka.actor.default-dispatcher-454   - state change from TERMINATING to TERMINATING -
2014-07-09 14:47:24,098 DEBUG application application-akka.actor.default-dispatcher-454   - Scheduling Delete for execution after 86399946 milliseconds -
2014-07-09 14:47:24,685 DEBUG application play-akka.actor.default-dispatcher-521   - received SOAP message /nsi-v2/ConnectionServiceRequester from 62.40.104.61 with content-type Some(text/xml) <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Header><ns7:nsiHeader xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns5="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns4="http://www.w3.org/2000/09/xmldsig#" xmlns:ns3="http://www.w3.org/2001/04/xmlenc#" xmlns:ns2="urn:oasis:names:tc:SAML:2.0:assertion"><protocolVersion>application/vnd.ogf.nsi.cs.v2.requester+soap</protocolVersion><correlationId>urn:uuid:fa5cc71c-2067-4c2a-974c-9c6019b2b306</correlationId><requesterNSA>urn:ogf:network:es.net:2013:nsa:nsi-aggr-west</requesterNSA><providerNSA>urn:ogf:network:geant.net:2013:nsa</providerNSA></ns7:nsiHeader></soap:Header><soap:Body><ns5:error xmlns:ns2="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns3="http://www.w3.org/2001/04/xmlenc#" xmlns:ns4="http://www.w3.org/2000/09/xmldsig#" xmlns:ns5="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/headers"><serviceException><nsaId>urn:ogf:network:geant.net:2013:nsa</nsaId><errorId>00201</errorId><text>Connection state machine is in invalid stated for received message</text><variables><variable type="terminate"><value>invalid transition for terminate while in TERMINATED state</value></variable></variables></serviceException></ns5:error></soap:Body></soap:Envelope> -
2014-07-09 14:47:24,688 DEBUG application play-akka.actor.default-dispatcher-521   - SOAP message parse result Success([#document: null]) -
2014-07-09 14:47:24,691 DEBUG application play-internal-execution-context-1   - Received (/nsi-v2/ConnectionServiceRequester): Success(NsiRequesterMessage(NsiHeaders(urn:uuid:fa5cc71c-2067-4c2a-974c-9c6019b2b306,urn:ogf:network:es.net:2013:nsa:nsi-aggr-west,urn:ogf:network:geant.net:2013:nsa,None,application/vnd.ogf.nsi.cs.v2.requester+soap,List(),List()),Error(org.ogf.schemas.nsi._2013._12.connection.types.GenericErrorType@18d84dad[serviceException=org.ogf.schemas.nsi._2013._12.framework.types.ServiceExceptionType@53c74a2[nsaId=urn:ogf:network:geant.net:2013:nsa, connectionId=<null>, serviceType=<null>, errorId=00201, text=Connection state machine is in invalid stated for received message, variables=org.ogf.schemas.nsi._2013._12.framework.types.VariablesType@671e69b7[variable={org.ogf.schemas.nsi._2013._12.framework.types.TypeValuePairType@54c89cd8[value={invalid transition for terminate while in TERMINATED state}, any=<null>, type=terminate, namespace=<null>]}], childException=<null>]]))) -
2014-07-09 14:47:24,696 DEBUG application play-akka.actor.default-dispatcher-521   - Ack 62.40.104.61 with Success(<?xml version="1.0" encoding="UTF-8" standalone="no"?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Header><ns7:nsiHeader xmlns:ns2="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns3="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns4="http://www.w3.org/2001/04/xmlenc#" xmlns:ns5="http://www.w3.org/2000/09/xmldsig#" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns8="http://schemas.ogf.org/nsi/2013/12/services/point2point" xmlns:ns9="http://nordu.net/namespaces/2013/12/gnsbod"><protocolVersion>application/vnd.ogf.nsi.cs.v2.requester+soap</protocolVersion><correlationId>urn:uuid:fa5cc71c-2067-4c2a-974c-9c6019b2b306</correlationId><requesterNSA>urn:ogf:network:es.net:2013:nsa:nsi-aggr-west</requesterNSA><providerNSA>urn:ogf:network:geant.net:2013:nsa</providerNSA></ns7:nsiHeader></soapenv:Header><soapenv:Body><ns2:acknowledgment xmlns:ns2="http://schemas.ogf.org/nsi/2013/12/connection/types" xmlns:ns3="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:ns4="http://www.w3.org/2001/04/xmlenc#" xmlns:ns5="http://www.w3.org/2000/09/xmldsig#" xmlns:ns6="http://schemas.ogf.org/nsi/2013/12/framework/types" xmlns:ns7="http://schemas.ogf.org/nsi/2013/12/framework/headers" xmlns:ns8="http://schemas.ogf.org/nsi/2013/12/services/point2point" xmlns:ns9="http://nordu.net/namespaces/2013/12/gnsbod"/></soapenv:Body></soapenv:Envelope>) -
erikrozendaal commented 8 years ago

@jmacauley Safnari error handling has been improved during the last year. Closing this issue. Please reopen if this is still applicable.