Check expires in request rspec and fail createsliver as appropriate

[lnevers@bbn.com]

Created a 2 VM sliver at the GPO SM with 2 VMs and 1 lan (attaching RSpec) and the sliver failed as follows:

$ omni.py sliverstatus -a eg-gpo lnexp ./exo-2vm-1lan-bbn.rspec 
INFO:omni:Loading config file /home/lnevers/.gcf/omni_config
INFO:omni:Using control framework pg
INFO:omni:Substituting AM nickname eg-gpo with URL https://bbn-hn.exogeni.net:11443/orca/xmlrpc, URN unspecified_AM_URN
INFO:omni:Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp expires on 2013-03-26 00:00:00 UTC
INFO:omni:Substituting AM nickname eg-gpo with URL https://bbn-hn.exogeni.net:11443/orca/xmlrpc, URN unspecified_AM_URN
INFO:omni:Status of Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp:
INFO:omni:Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp at AM https://bbn-hn.exogeni.net:11443/orca/xmlrpc has overall SliverStatus: failed
INFO:omni:Sliver status for Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp at AM URL https://bbn-hn.exogeni.net:11443/orca/xmlrpc
INFO:omni:{
  "geni_status": "failed", 
  "geni_urn": "urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp", 
  "geni_resources": [
    {
      "orca_expires": "Tue Mar 12 16:07:42 UTC 2013", 
      "geni_urn": "urn:publicid:IDN+exogeni.net:bbnvmsite+sliver+f2f8a638-2547-4882-a043-8cb7e21b5c7f#geni1", 
      "geni_error": "Reservation 0bc447cb-890e-4e8a-890c-5dcc09bad1bb (Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp) is in state 
[Failed,None], err=unexpected ticket failure, message=negative duration for term, 
stack=Exception stack trace: \norca.shirako.time.Term.validate(Term.java:773)
\norca.shirako.kernel.ReservationClient.validateOutgoing(ReservationClient.java:2288)
\norca.shirako.kernel.KernelWrapper.ticket(KernelWrapper.java:874)
\norca.shirako.core.ServiceManager.bid(ServiceManager.java:142)
\norca.shirako.core.ServiceManager.tickHandler(ServiceManager.java:469)
\norca.shirako.core.Actor.actorTick(Actor.java:431)\norca.shirako.core.Actor.access$000(Actor.java:51)
\norca.shirako.core.Actor$1.process(Actor.java:341)\norca.shirako.core.Actor.actorMain(Actor.java:384)
\norca.shirako.core.Actor$4.run(Actor.java:944)\njava.lang.Thread.run(Thread.java:662)\n\n", 
      "geni_status": "Failed"
    }, 
    {
      "orca_expires": "Tue Mar 12 16:07:42 UTC 2013", 
      "geni_urn": "urn:publicid:IDN+exogeni.net:bbnvmsite+sliver+f2f8a638-2547-4882-a043-8cb7e21b5c7f#center", 
      "geni_error": "Reservation 12346895-8f39-424a-a163-6f188dc2b4a3 (Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp) is in state 
[Failed,None], err=unexpected ticket failure, message=negative duration for term, stack=Exception stack trace: 
\norca.shirako.time.Term.validate(Term.java:773)
\norca.shirako.kernel.ReservationClient.validateOutgoing(ReservationClient.java:2288)
\norca.shirako.kernel.KernelWrapper.ticket(KernelWrapper.java:874)
\norca.shirako.core.ServiceManager.bid(ServiceManager.java:142)
\norca.shirako.core.ServiceManager.tickHandler(ServiceManager.java:469)
\norca.shirako.core.Actor.actorTick(Actor.java:431)\norca.shirako.core.Actor.access$000(Actor.java:51)
\norca.shirako.core.Actor$1.process(Actor.java:341)\norca.shirako.core.Actor.actorMain(Actor.java:384)
\norca.shirako.core.Actor$4.run(Actor.java:944)\njava.lang.Thread.run(Thread.java:662)\n\n", 
      "geni_status": "Failed"
    }, 
    {
      "orca_expires": "Tue Mar 12 16:07:42 UTC 2013", 
      "geni_urn": "urn:publicid:IDN+exogeni.net:bbnvmsite+sliver+f2f8a638-2547-4882-a043-8cb7e21b5c7f#geni2", 
      "geni_error": "Reservation 7cf2a6be-cb2c-423b-8b4a-6bc54fd6246d (Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp) is
 in state [Failed,None], err=unexpected ticket failure, message=negative duration for term, stack=Exception stack trace: 
\norca.shirako.time.Term.validate(Term.java:773) \norca.shirako.kernel.ReservationClient.validateOutgoing(ReservationClient.java:2288)
\norca.shirako.kernel.KernelWrapper.ticket(KernelWrapper.java:874)\norca.shirako.core.ServiceManager.bid(ServiceManager.java:142)
\norca.shirako.core.ServiceManager.tickHandler(ServiceManager.java:469)\norca.shirako.core.Actor.actorTick(Actor.java:431)
\norca.shirako.core.Actor.access$000(Actor.java:51)\norca.shirako.core.Actor$1.process(Actor.java:341)
\norca.shirako.core.Actor.actorMain(Actor.java:384)\norca.shirako.core.Actor$4.run(Actor.java:944)
\njava.lang.Thread.run(Thread.java:662)\n\n", 
      "geni_status": "Failed"
    }
  ]
}
INFO:omni: ------------------------------------------------------------
INFO:omni: Completed sliverstatus:

  Options as run:
		aggregate: ['eg-gpo']
		framework: pg

  Args: sliverstatus lnexp ./exo-2vm-1lan-bbn.rspec

  Result Summary: Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp expires on 2013-03-26 00:00:00 UTC
Slice urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp at AM https://bbn-hn.exogeni.net:11443/orca/xmlrpc has overall SliverStatus: failed.
 Returned status of slivers on 1 of 1 possible aggregates. 
INFO:omni: ============================================================

[lnevers@bbn.com]

Attached request RSpec as well as a log of the sliver creation

[lnevers@bbn.com]

Just realized that the request RSpec has the following "expires="2013-03-12T16:07:42Z"" which is in the past. Not sure if it is the reason for the failure, but just noting the test condition.

[ibaldin@renci.org]

16:07Z is already passed. What's the issue?

[lnevers@bbn.com]

Error handling is not ideal. The request was processed and then failed at the ticket stage. I happened to catch the failure because I issued a sliverstatus at the right time, and subsequent sliverstatus report:

Failed to get SliverStatus on lnexp at AM https://bbn-hn.exogeni.net:11443/orca/xmlrpc: 
Error from Aggregate: code 2: ERROR: unable to get slice status for 
urn:publicid:IDN+pgeni.gpolab.bbn.com+slice+lnexp.

The subsequent sliver status is accurate, but it is hard for the experimenter to determine the source of the failure, unless one issues a sliver status at the right time. It also does not help that rspeclint did not catch the "expires" value in the past. Is this something that can be caught before resource ticketing?

[ahelsing@bbn.com]

sounds like this ticket is really a request that when processing the original request rspec, if the 'expires' attribute is already in the past (or within some epsilon of now), that the request be failed then with an error like "Rspec expires is past or too soon".

[ahelsing@bbn.com]

at least include this on the orca-expires page

[ahelsing@bbn.com]

(err, orca-errors)

[lnevers@bbn.com]

Using version "ORCA Dungeness: v.4.0-SNAPSHOT.build-5468" on the NICTA rack was able to verify that an "expires" values in the past is handled.

In a scenario where expires="2013-05-12T16:07:42Z" was used, creating a sliver resulted in the following error:

Failed CreateSliver for slice lnexpired at https://nicta-hn.exogeni.net:11443/orca/xmlrpc.  
Error from Aggregate: code 2: Embedding workflow ERROR: -1:Term End time Sun May 12 
16:07:42 UTC 2013 should be after beginning time: start: Tue May 28 19:21:07 UTC 2013 
duration: 0 days 24 hours 0 minutes 0 seconds end: null.

[lnevers@bbn.com]

Using 'ORCA Dungeness: v.4.0-SNAPSHOT.build-5495' on BBN rack was able to verify that createsliver with "expires" attribute in the past are handled:

Result Summary: Failed CreateSliver for slice lnexo at https://bbn-hn.exogeni.net:11443/orca/xmlrpc. 
 Error from Aggregate: code 2: Embedding workflow ERROR: -1:Term End time Sun May 12
16:07:42 UTC 2013 should be after beginning time: start: Tue Jun 04 15:17:04 UTC 2013
 duration: 0 days 24 hours 0 minutes 0 seconds end: null.
 Please see https://geni-orca.renci.org/trac/wiki/orca-errors for possible solutions. 

Closing ticket.