wiki:GeniNetworkStitchingConfirmationTestStatus/Chicago

Version 10 (modified by lnevers@bbn.com, 9 years ago) (diff)

--

University of Chicago Stitching Confirmation Tests

This pages capture the detailed test logs for each test defined in the New Site Stitching Confirmation Tests page. For the sites status see the New Site Stitching Confirmation Tests Status page.

IG-ST-1 New Site to GPO IG topology

The Chicago site is an AL2S only site and advertises the following stitching details:

<stitching xmlns="http://hpn.east.isi.edu/rspec/ext/stitch/0.1/" lastUpdateTime="2014-09-18T18:17:36Z" >
<aggregate id="urn:publicid:IDN+geni.uchicago.edu+authority+cm" url="https://www.geni.uchicago.edu:12369/protogeni/xmlrpc/am">
<aggregatetype>protogeni</aggregatetype>
<stitchingmode>chainANDTree</stitchingmode>
<scheduledservices>false</scheduledservices>
<negotiatedservices>false</negotiatedservices>
<lifetime id="life">
    <start type="time">2014-09-18T18:17:36Z</start>
    <end type="time">2014-09-18T18:17:36Z</end>
</lifetime>
<node id="urn:publicid:IDN+geni.uchicago.edu+node+procurve2">
  <port id="urn:publicid:IDN+geni.uchicago.edu+stitchport+procurve2:1.16.al2s">
    <capacity>1000000</capacity>
    <maximumReservableCapacity>1000000</maximumReservableCapacity>
    <minimumReservableCapacity>1000</minimumReservableCapacity>
    <granularity>1</granularity>
    <link id="urn:publicid:IDN+geni.uchicago.edu+interface+procurve2:1.16.al2s">
      <remoteLinkId>urn:publicid:IDN+al2s.internet2.edu+interface+sdn-sw.star.net.internet2.edu:eth7/1:uchicago-ig</remoteLinkId>
      <trafficEngineeringMetric>10</trafficEngineeringMetric>
      <capacity>1000000</capacity>
      <maximumReservableCapacity>1000000</maximumReservableCapacity>
      <minimumReservableCapacity>1000</minimumReservableCapacity>
      <granularity>1</granularity>
      <switchingCapabilityDescriptor>
        <switchingcapType>l2sc</switchingcapType>
        <encodingType>ethernet</encodingType>
        <switchingCapabilitySpecificInfo>
         <switchingCapabilitySpecificInfo_L2sc>
          <interfaceMTU>1500</interfaceMTU>
          <vlanRangeAvailability>3075-3094</vlanRangeAvailability>
          <vlanTranslation>false</vlanTranslation>
         </switchingCapabilitySpecificInfo_L2sc>
        </switchingCapabilitySpecificInfo>
      </switchingCapabilityDescriptor>
    </link>
  </port>
</node>
</aggregate>
</stitching>

Experimenter may not need any of this data, but it is helpful to reference when trying to determine how many VLANs are delegated for stitching at the site or how much bandwidth can be requested.

Create a slice and then create the stitched slivers with the RSpec IG-ST-1-al2s.rspec:

$ stitcher.py createsliver IG-ST-1 IG-ST-1-al2s.rspec -o
10:10:54 INFO    : Configured logging from file /home/lnevers/gcf-2.7-rc2/src/gcf/stitcher_logging.conf
10:10:55 INFO    : Reading slice IG-ST-1 credential...
10:10:56 INFO    : Slice urn:publicid:IDN+ch.geni.net:ln-test+slice+IG-ST-1 expires on 2014-10-02 19:30:02 UTC
10:10:56 INFO    : Using SCS at http://nutshell.maxgigapop.net:8081/geni/xmlrpc
10:10:56 INFO    : Calling SCS...
10:11:00 INFO    : Multi-AM reservation will include resources from these aggregates:
10:11:00 INFO    : 	<Aggregate chicago-ig>
10:11:00 INFO    : 	<Aggregate gpo-ig>
10:11:00 INFO    : 	<Aggregate oess>
10:11:00 INFO    : 	<Aggregate ion>
10:11:00 INFO    : Stitcher doing createsliver at <Aggregate chicago-ig>...
10:11:20 INFO    : ... Allocation at <Aggregate chicago-ig> complete.
10:11:20 INFO    : Stitcher doing createsliver at <Aggregate gpo-ig>...
10:11:35 INFO    : ... Allocation at <Aggregate gpo-ig> complete.
10:11:35 INFO    : Stitcher doing createsliver at <Aggregate oess>...
10:11:39 INFO    : ... Allocation at <Aggregate oess> complete.
10:11:39 INFO    : Stitcher doing createsliver at <Aggregate ion>...
10:12:25 INFO    : DCN AM <Aggregate ion>: must wait for status ready....
10:12:25 INFO    : Pausing 30 seconds to let circuit become ready...
10:13:03 INFO    : DCN circuit 120141 is ready at <Aggregate ion>
10:13:10 INFO    : ... Allocation at <Aggregate ion> complete.
10:13:10 INFO    : All aggregates are complete.
10:13:10 INFO    : Your resources expire at 2014-10-02T14:01:00 (UTC). 
10:13:10 INFO    : Saved combined reservation RSpec at 4 AMs to file '/home/lnevers/gcf-test/stitch-test/Chicago/IG-ST-1-manifest-rspec-multiam-combined.xml'
Success: Reserved resources in slice IG-ST-1 at 4 Aggregates (including 2 intermediate aggregate(s) not in the original request), creating 1 stitched link(s).

Determined login information at each Chicago and GPO aggregate:

$ readyToLogin.py IG-ST-1 -a chicago-ig
  ....
ig-chic's geni_status is: ready 
User lnevers logs in to ig-chic using:
	ssh -p 30266  -i /home/lnevers/.ssh/geni_cert_portal_key lnevers@pc2.geni.uchicago.edu

$ readyToLogin.py IG-ST-1 -a gpo-ig
  ....
ig-gpo's geni_status is: ready 
User lnevers logs in to ig-gpo using:
	ssh -p 36922  -i /home/lnevers/.ssh/geni_cert_portal_key lnevers@pc4.instageni.gpolab.bbn.com

Measurements

Iperf InstaGENI GPO VM to InstaGENI Chicago VM (TCP) - TCP window size: 23.5 KByte (default)

Collected: 2014-09-29

One Client_

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.1 sec   142 MBytes  19.8 Mbits/sec

Five Clients

[ ID] Interval       Transfer     Bandwidth
[  7]  0.0-60.1 sec  27.8 MBytes  3.87 Mbits/sec
[  4]  0.0-60.1 sec  28.2 MBytes  3.94 Mbits/sec
[  6]  0.0-60.3 sec  30.9 MBytes  4.30 Mbits/sec
[  3]  0.0-60.4 sec  26.1 MBytes  3.63 Mbits/sec
[  5]  0.0-60.5 sec  31.4 MBytes  4.35 Mbits/sec
[SUM]  0.0-60.5 sec   144 MBytes  20.0 Mbits/sec

Ten Clients

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-59.7 sec  17.4 MBytes  2.44 Mbits/sec
[  4]  0.0-59.7 sec  9.75 MBytes  1.37 Mbits/sec
[  9]  0.0-60.8 sec  20.8 MBytes  2.86 Mbits/sec
[  5]  0.0-60.8 sec  12.9 MBytes  1.78 Mbits/sec
[ 10]  0.0-60.9 sec  17.2 MBytes  2.38 Mbits/sec
[  8]  0.0-61.0 sec  10.5 MBytes  1.44 Mbits/sec
[  7]  0.0-61.1 sec  14.4 MBytes  1.97 Mbits/sec
[ 11]  0.0-61.1 sec  11.8 MBytes  1.61 Mbits/sec
[  6]  0.0-61.3 sec  11.9 MBytes  1.63 Mbits/sec
[ 12]  0.0-61.7 sec  20.4 MBytes  2.77 Mbits/sec
[SUM]  0.0-61.7 sec   147 MBytes  20.0 Mbits/sec

Iperf InstaGENI GPO VM to InstaGENI Chicago VM (UDP) - UDP buffer size: 224 KByte (default)

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.0 sec   719 MBytes   101 Mbits/sec
[  3] Sent 512812 datagrams
[  3] Server Report:
[  3]  0.0-60.2 sec   139 MBytes  19.4 Mbits/sec  12.842 ms 413469/512811 (81%)
[  3]  0.0-60.2 sec  1 datagrams received out-of-order

Ping from InstaGENI GPO VM to InstaGENI Chicago VM

60 packets transmitted, 60 received, 0% packet loss, time 59087ms
rtt min/avg/max/mdev = 33.056/33.352/33.845/0.142 ms

Iperf InstaGENI Chicago VM to InstaGENI GPO VM (TCP) - TCP window size: 23.5 KByte (default)

Collected: 2014-09-29

One Client_

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.1 sec   140 MBytes  19.5 Mbits/sec

Five Clients

[ ID] Interval       Transfer     Bandwidth
[  7]  0.0-60.1 sec  29.2 MBytes  4.08 Mbits/sec
[  4]  0.0-60.5 sec  37.0 MBytes  5.13 Mbits/sec
[  5]  0.0-60.6 sec  30.2 MBytes  4.19 Mbits/sec
[  6]  0.0-60.7 sec  26.4 MBytes  3.65 Mbits/sec
[  3]  0.0-60.8 sec  21.8 MBytes  3.00 Mbits/sec
[SUM]  0.0-60.8 sec   145 MBytes  20.0 Mbits/sec

Ten Clients

[ ID] Interval       Transfer     Bandwidth
[ 10]  0.0-60.0 sec  16.6 MBytes  2.32 Mbits/sec
[  3]  0.0-60.2 sec  11.9 MBytes  1.65 Mbits/sec
[ 12]  0.0-60.3 sec  11.2 MBytes  1.56 Mbits/sec
[  6]  0.0-60.4 sec  17.1 MBytes  2.38 Mbits/sec
[  9]  0.0-60.8 sec  17.5 MBytes  2.42 Mbits/sec
[  8]  0.0-60.9 sec  13.9 MBytes  1.91 Mbits/sec
[  4]  0.0-61.0 sec  18.2 MBytes  2.51 Mbits/sec
[  7]  0.0-61.1 sec  15.5 MBytes  2.13 Mbits/sec
[  5]  0.0-61.7 sec  9.00 MBytes  1.22 Mbits/sec
[ 11]  0.0-62.4 sec  16.0 MBytes  2.15 Mbits/sec
[SUM]  0.0-62.4 sec   147 MBytes  19.8 Mbits/sec

Iperf InstaGENI Chicago VM to InstaGENI GPO VM (UDP) - UDP buffer size: 224 KByte (default)

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.0 sec   719 MBytes   100 Mbits/sec
[  3] Sent 512753 datagrams
[  3] Server Report:
[  3]  0.0-60.2 sec   139 MBytes  19.4 Mbits/sec  14.514 ms 413397/512750 (81%)
[  3]  0.0-60.2 sec  1 datagrams received out-of-order

Ping from InstaGENI Chicago VM to InstaGENI GPO VM

60 packets transmitted, 60 received, 0% packet loss, time 59086ms
rtt min/avg/max/mdev = 33.113/33.383/35.543/0.363 ms

IG-ST-2 New Site to GPO IG Loop topology

Create a slice and then create the stitched slivers with the RSpec IG-ST-2.rspec:

$ stitcher.py createsliver IG-ST-2 IG-ST-2.rspec -o
10:34:50 INFO    : Configured logging from file /home/lnevers/gcf-2.7-rc2/src/gcf/stitcher_logging.conf
10:34:51 INFO    : Reading slice IG-ST-2 credential...
10:34:51 INFO    : Slice urn:publicid:IDN+ch.geni.net:ln-test+slice+IG-ST-2 expires on 2014-10-06 14:31:12 UTC
10:34:51 INFO    : Using SCS at http://nutshell.maxgigapop.net:8081/geni/xmlrpc
10:34:51 INFO    : Calling SCS...
10:34:56 INFO    : Multi-AM reservation will include resources from these aggregates:
10:34:56 INFO    : 	<Aggregate chicago-ig>
10:34:56 INFO    : 	<Aggregate gpo-ig>
10:34:56 INFO    : 	<Aggregate oess>
10:34:56 INFO    : 	<Aggregate ion>
10:34:56 INFO    : Stitcher doing createsliver at <Aggregate chicago-ig>...
10:35:17 INFO    : ... Allocation at <Aggregate chicago-ig> complete.
10:35:17 INFO    : Stitcher doing createsliver at <Aggregate gpo-ig>...
10:35:33 INFO    : ... Allocation at <Aggregate gpo-ig> complete.
10:35:33 INFO    : Stitcher doing createsliver at <Aggregate oess>...
10:35:40 INFO    : ... Allocation at <Aggregate oess> complete.
10:35:40 INFO    : Stitcher doing createsliver at <Aggregate ion>...
10:36:26 INFO    : DCN AM <Aggregate ion>: must wait for status ready....
10:36:26 INFO    : Pausing 30 seconds to let circuit become ready...
10:37:03 INFO    : Pausing 30 seconds to let circuit become ready...
10:37:41 INFO    : DCN circuit 120151 is ready at <Aggregate ion>
10:37:41 INFO    : DCN circuit 120161 is ready at <Aggregate ion>
10:37:48 INFO    : ... Allocation at <Aggregate ion> complete.
10:37:48 INFO    : All aggregates are complete.
10:37:48 INFO    : Your resources expire at 2014-10-05T14:24:56 (UTC). 
10:37:48 INFO    : Saved combined reservation RSpec at 4 AMs to file '/home/lnevers/gcf-test/stitch-test/Chicago/IG-ST-2-manifest-rspec-multiam-combined.xml'
Success: Reserved resources in slice IG-ST-2 at 4 Aggregates (including 2 intermediate aggregate(s) not in the original request), creating 2 stitched link(s).

Determined login information at each Chicago and GPO aggregate:

$ readyToLogin.py IG-ST-2 -a chicago-ig
  ....
ig-chic's geni_status is: ready 
User lnevers logs in to ig-chic using:
	ssh -p 30522  -i /home/lnevers/.ssh/geni_cert_portal_key lnevers@pc1.geni.uchicago.edu

$ readyToLogin.py IG-ST-2 -a gpo-ig
  ....
ig-gpo's geni_status is: ready 
User lnevers logs in to ig-gpo using:
	ssh -p 37178  -i /home/lnevers/.ssh/geni_cert_portal_key lnevers@pc1.instageni.gpolab.bbn.com

Login to the GPO host and ping the remote on each of the two interfaces:

[lnevers@ig-gpo ~]$ ping 10.10.4.2 -c 60 -q
PING 10.10.4.2 (10.10.4.2) 56(84) bytes of data.

--- 10.10.4.2 ping statistics ---
60 packets transmitted, 60 received, 0% packet loss, time 59097ms
rtt min/avg/max/mdev = 32.605/33.315/66.416/4.314 ms
[lnevers@ig-gpo ~]$ ping 192.168.4.2 -c 60 -q
PING 192.168.4.2 (192.168.4.2) 56(84) bytes of data.

--- 192.168.4.2 ping statistics ---
60 packets transmitted, 60 received, 0% packet loss, time 59097ms
rtt min/avg/max/mdev = 32.546/33.284/66.594/4.338 ms
[lnevers@ig-gpo ~]$ 

IG-ST-3 IG-ST-3 New Site 3 node linear topology

Create a slice and then create the stitched slivers with the RSpec IG-ST-3.rspec:

$ stitcher.py createsliver IG-ST-3 IG-ST-3.rspec -o
09:38:55 INFO    : Configured logging from file /home/lnevers/gcf-2.7-rc2/src/gcf/stitcher_logging.conf
09:38:55 INFO    : Reading slice IG-ST-3 credential...
09:38:56 INFO    : Slice urn:publicid:IDN+ch.geni.net:ln-test+slice+IG-ST-3 expires on 2014-10-06 14:37:17 UTC
09:38:56 INFO    : Calling SCS...
09:39:01 INFO    : Multi-AM reservation will include resources from these aggregates:
09:39:01 INFO    : 	<Aggregate chicago-ig>
09:39:01 INFO    : 	<Aggregate oess>
09:39:01 INFO    : 	<Aggregate utah-ig>
09:39:01 INFO    : 	<Aggregate gpo-ig>
09:39:01 INFO    : 	<Aggregate ion>
09:39:01 INFO    : 	<Aggregate utah-pg>
09:39:01 INFO    : Stitcher doing createsliver at <Aggregate chicago-ig>...
09:39:20 INFO    : ... Allocation at <Aggregate chicago-ig> complete.
09:39:21 INFO    : Stitcher doing createsliver at <Aggregate gpo-ig>...
09:39:35 INFO    : ... Allocation at <Aggregate gpo-ig> complete.
09:39:35 INFO    : Stitcher doing createsliver at <Aggregate utah-pg>...
09:40:24 INFO    : ... Allocation at <Aggregate utah-pg> complete.
09:40:24 INFO    : Stitcher doing createsliver at <Aggregate oess>...
09:40:34 INFO    : ... Allocation at <Aggregate oess> complete.
09:40:34 INFO    : Stitcher doing createsliver at <Aggregate utah-ig>...
09:40:55 INFO    : ... Allocation at <Aggregate utah-ig> complete.
09:40:55 INFO    : Stitcher doing createsliver at <Aggregate ion>...
09:41:40 INFO    : DCN AM <Aggregate ion>: must wait for status ready....
09:41:40 INFO    : Pausing 30 seconds to let circuit become ready...
09:42:18 INFO    : Pausing 30 seconds to let circuit become ready...
09:42:56 WARNING : sliverstatus: 120431 is (still) failed at <Aggregate ion>. Delete and retry.
09:42:56 WARNING : sliverstatus: 120421 is (still) failed at <Aggregate ion>. Delete and retry.
09:42:56 WARNING :   Status had error message: VLAN cancelled by rollback from contingent failure
09:43:04 WARNING : <Aggregate ion> says requested VLAN was unavailable at <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.newy:ae0:bbn' on path u'link'>
09:43:04 INFO    : Deleting some reservations to retry, avoiding failed VLAN...
09:43:04 INFO    : Doing deletesliver at <Aggregate gpo-ig>...
09:43:56 INFO    : Will put <Aggregate ion> back in the pool to allocate. Got: Retrying reservations at earlier AMs to avoid unavailable VLAN tag at <Aggregate ion>....
09:43:56 INFO    : Pausing for 30 seconds for Aggregates to free up resources...


09:44:26 INFO    : Stitcher doing createsliver at <Aggregate gpo-ig>...
09:44:41 INFO    : ... Allocation at <Aggregate gpo-ig> complete.
09:44:41 INFO    : Stitcher doing createsliver at <Aggregate ion>...
09:45:26 INFO    : DCN AM <Aggregate ion>: must wait for status ready....
09:45:26 INFO    : Pausing 30 seconds to let circuit become ready...
09:46:04 INFO    : Pausing 30 seconds to let circuit become ready...
09:46:41 INFO    : DCN circuit 120441 is ready at <Aggregate ion>
09:46:41 INFO    : DCN circuit 120451 is ready at <Aggregate ion>
09:46:49 INFO    : ... Allocation at <Aggregate ion> complete.
09:46:49 INFO    : All aggregates are complete.
09:46:49 INFO    : Your resources expire at 2014-10-05T13:29:01 (UTC). 
09:46:49 INFO    : Saved combined reservation RSpec at 6 AMs to file '/home/lnevers/gcf-test/stitch-test/Chicago/IG-ST-3-manifest-rspec-multiam-combined.xml'
Success: Reserved resources in slice IG-ST-3 at 6 Aggregates (including 3 intermediate aggregate(s) not in the original request), creating 2 stitched link(s).

Determined login information the Chicago host:

$ readyToLogin.py IG-ST-3 -a chicago-ig
  ....
ig-chic's geni_status is: ready 
User lnevers logs in to ig-chic using:
	ssh -p 30010  -i /home/lnevers/.ssh/geni_cert_portal_key lnevers@pc1.geni.uchicago.edu

Login to the Chicago host and ping each remote:

#ping GPO IG 
[lnevers@ig-chic ~]$ ping 192.168.2.1 -c 60 -q
PING 192.168.2.1 (192.168.2.1) 56(84) bytes of data.

--- 192.168.2.1 ping statistics ---
60 packets transmitted, 60 received, 0% packet loss, time 59076ms
rtt min/avg/max/mdev = 41.913/42.760/84.736/5.473 ms

# Utah IG
[lnevers@ig-chic ~]$ ping 192.168.4.1 -c 60 -q
PING 192.168.4.1 (192.168.4.1) 56(84) bytes of data.

--- 192.168.4.1 ping statistics ---
60 packets transmitted, 60 received, 0% packet loss, time 59085ms
rtt min/avg/max/mdev = 88.070/89.922/183.792/12.227 ms

IG-ST-4 New Site to GPO EG interoperability

IG-ST-5 Site Information

Various pages include stitching information for a site. Each of the following were verified for this site:

  1. Verified that stitching VLANs and Device URN information exists in the Chicago Aggregate page.

  1. Verified that Delegated GENI Stitching VLANs for site are documented at the Delegated GENI Stitching VLANs.
  1. Stitching Computation Service logs were reviewed while testing stitching to this site, no issues found.
  1. TO BE Added site to the list of GENI Network Stitching Sites.

IG-ST-6 New Site OpenFlow topology

Create a slice and then create the stitched slivers using OpenFlow with the RSPec IG-ST-6.rspec:

$ stitcher createsliver IG-ST-6 ./IG-ST-6.rspec 
10:55:31 INFO    : Configured logging from file /home/lnevers/gcf-2.7-rc2/src/gcf/stitcher_logging.conf
10:55:32 INFO    : Reading slice IG-ST-6 credential...
10:55:32 INFO    : Slice urn:publicid:IDN+ch.geni.net:ln-test+slice+IG-ST-6 expires on 2014-10-06 14:55:19 UTC
10:55:32 INFO    : Using SCS at http://nutshell.maxgigapop.net:8081/geni/xmlrpc
10:55:32 INFO    : Calling SCS...
10:55:35 INFO    : Multi-AM reservation will include resources from these aggregates:
10:55:35 INFO    : 	<Aggregate chicago-ig>
10:55:35 INFO    : 	<Aggregate gpo-ig>
10:55:35 INFO    : 	<Aggregate oess>
10:55:35 INFO    : 	<Aggregate ion>
10:55:35 INFO    : Stitcher doing createsliver at <Aggregate chicago-ig>...
10:55:52 INFO    : ... Allocation at <Aggregate chicago-ig> complete.
10:55:52 INFO    : Stitcher doing createsliver at <Aggregate gpo-ig>...
10:56:09 INFO    : ... Allocation at <Aggregate gpo-ig> complete.
10:56:10 INFO    : Stitcher doing createsliver at <Aggregate oess>...
10:56:14 INFO    : ... Allocation at <Aggregate oess> complete.
10:56:14 INFO    : Stitcher doing createsliver at <Aggregate ion>...
10:56:59 INFO    : DCN AM <Aggregate ion>: must wait for status ready....
10:56:59 INFO    : Pausing 30 seconds to let circuit become ready...
10:57:37 WARNING : sliverstatus: 120221 is (still) failed at <Aggregate ion>. Delete and retry.
10:57:43 WARNING : <Aggregate ion> says requested VLAN was unavailable at <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.newy:ae0:bbn' on path u'link'>
10:57:43 INFO    : Deleting some reservations to retry, avoiding failed VLAN...
10:57:43 INFO    : Doing deletesliver at <Aggregate gpo-ig>...
10:59:10 ERROR   :  {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+4f8b801e2b465cb63a9580ff428a2532', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=4f8b801e2b465cb63a9580ff428a2532'}, 'value': 0}
11:00:51 ERROR   :  {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+c10dd3f13b099ad9f753902b2bd5d735', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=c10dd3f13b099ad9f753902b2bd5d735'}, 'value': 0}
11:02:27 ERROR   :  {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+9962682bfe431c9636ec6a7e63e0212f', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=9962682bfe431c9636ec6a7e63e0212f'}, 'value': 0}
11:03:41 INFO    : Will put <Aggregate ion> back in the pool to allocate. Got: Retrying reservations at earlier AMs to avoid unavailable VLAN tag at <Aggregate ion>....
11:03:41 INFO    : Pausing for 30 seconds for Aggregates to free up resources...

11:04:11 INFO    : Stitcher doing createsliver at <Aggregate gpo-ig>...
11:04:26 INFO    : ... Allocation at <Aggregate gpo-ig> complete.
11:04:26 INFO    : Stitcher doing createsliver at <Aggregate ion>...
11:05:12 INFO    : DCN AM <Aggregate ion>: must wait for status ready....
11:05:12 INFO    : Pausing 30 seconds to let circuit become ready...
11:05:49 INFO    : DCN circuit 120251 is ready at <Aggregate ion>
11:05:56 INFO    : ... Allocation at <Aggregate ion> complete.
11:05:56 INFO    : All aggregates are complete.
11:05:56 INFO    : Your resources expire at 2014-10-05T14:45:35 (UTC). 
11:05:56 INFO    : Saved combined reservation RSpec at 4 AMs to file '/home/lnevers/gcf-test/stitch-test/Chicago/IG-ST-6-manifest-rspec-multiam-combined.xml'
Success: Reserved resources in slice IG-ST-6 at 4 Aggregates (including 2 intermediate aggregate(s) not in the original request), creating 1 stitched link(s).

Determined login information at each Chicago and GPO aggregate:

$ readyToLogin.py IG-ST-6 -a chicago-ig
  ....
ig-chic's geni_status is: ready 
User lnevers logs in to ig-chic using:
	ssh -p 30522  -i /home/lnevers/.ssh/geni_cert_portal_key lnevers@pc2.geni.uchicago.edu

$ readyToLogin.py IG-ST-6 -a gpo-ig
  ....
ig-gpo's geni_status is: ready 
User lnevers logs in to ig-gpo using:
	ssh -p 37178  -i /home/lnevers/.ssh/geni_cert_portal_key lnevers@pc4.instageni.gpolab.bbn.com

Measurements

Iperf InstaGENI GPO VM to InstaGENI Chicago VM (TCP) - TCP window size: 23.5 KByte (default)

Collected: 2014-09-29

One Client_

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.2 sec   141 MBytes  19.7 Mbits/sec

Five Clients

[ ID] Interval       Transfer     Bandwidth
[  4]  0.0-60.4 sec  25.0 MBytes  3.47 Mbits/sec
[  7]  0.0-60.4 sec  35.5 MBytes  4.93 Mbits/sec
[  3]  0.0-60.6 sec  28.4 MBytes  3.93 Mbits/sec
[  6]  0.0-61.0 sec  28.0 MBytes  3.85 Mbits/sec
[  5]  0.0-61.1 sec  25.4 MBytes  3.48 Mbits/sec
[SUM]  0.0-61.1 sec   142 MBytes  19.5 Mbits/sec

Ten Clients

[ ID] Interval       Transfer     Bandwidth
[ 12]  0.0-60.5 sec  18.1 MBytes  2.51 Mbits/sec
[  8]  0.0-60.7 sec  18.9 MBytes  2.61 Mbits/sec
[ 11]  0.0-60.9 sec  14.2 MBytes  1.96 Mbits/sec
[  6]  0.0-61.3 sec  15.0 MBytes  2.05 Mbits/sec
[  7]  0.0-61.4 sec  11.9 MBytes  1.62 Mbits/sec
[ 10]  0.0-61.4 sec  16.5 MBytes  2.25 Mbits/sec
[  9]  0.0-61.5 sec  12.4 MBytes  1.69 Mbits/sec
[  4]  0.0-61.8 sec  9.12 MBytes  1.24 Mbits/sec
[  5]  0.0-62.0 sec  15.4 MBytes  2.08 Mbits/sec
[  3]  0.0-62.2 sec  14.1 MBytes  1.90 Mbits/sec
[SUM]  0.0-62.2 sec   146 MBytes  19.6 Mbits/sec

Iperf InstaGENI GPO VM to InstaGENI Chicago VM (UDP) - UDP buffer size: 224 KByte (default)

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.0 sec   719 MBytes   101 Mbits/sec
[  3] Sent 512815 datagrams
[  3] Server Report:
[  3]  0.0-60.1 sec   139 MBytes  19.4 Mbits/sec   7.825 ms 413864/512814 (81%)
[  3]  0.0-60.1 sec  91 datagrams received out-of-order

Ping from InstaGENI GPO VM to InstaGENI Chicago VM

60 packets transmitted, 60 received, 0% packet loss, time 59085ms
rtt min/avg/max/mdev = 33.024/39.046/178.801/25.305 ms

Iperf InstaGENI Chicago VM to InstaGENI GPO VM (TCP) - TCP window size: 23.5 KByte (default)

Collected: 2014-09-29

One Client_

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.4 sec   138 MBytes  19.2 Mbits/sec

Five Clients

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.4 sec  27.9 MBytes  3.87 Mbits/sec
[  4]  0.0-60.5 sec  26.1 MBytes  3.62 Mbits/sec
[  6]  0.0-60.5 sec  34.6 MBytes  4.80 Mbits/sec
[  7]  0.0-60.8 sec  26.0 MBytes  3.59 Mbits/sec
[  5]  0.0-61.2 sec  28.5 MBytes  3.91 Mbits/sec
[SUM]  0.0-61.2 sec   143 MBytes  19.6 Mbits/sec

Ten Clients

[ ID] Interval       Transfer     Bandwidth
[  4]  0.0-59.1 sec  16.8 MBytes  2.38 Mbits/sec
[ 10]  0.0-60.1 sec  17.4 MBytes  2.43 Mbits/sec
[  7]  0.0-60.2 sec  13.1 MBytes  1.83 Mbits/sec
[  8]  0.0-60.2 sec  14.2 MBytes  1.99 Mbits/sec
[  6]  0.0-60.2 sec  11.8 MBytes  1.64 Mbits/sec
[ 12]  0.0-60.3 sec  11.5 MBytes  1.60 Mbits/sec
[  5]  0.0-60.3 sec  19.1 MBytes  2.66 Mbits/sec
[  9]  0.0-60.6 sec  16.5 MBytes  2.28 Mbits/sec
[  3]  0.0-60.7 sec  14.4 MBytes  1.99 Mbits/sec
[ 11]  0.0-61.3 sec  9.50 MBytes  1.30 Mbits/sec
[SUM]  0.0-61.3 sec   144 MBytes  19.8 Mbits/sec

Iperf InstaGENI Chicago VM to InstaGENI GPO VM (UDP) - UDP buffer size: 224 KByte (default)

[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-60.0 sec   719 MBytes   101 Mbits/sec
[  3] Sent 512783 datagrams
[  3] Server Report:
[  3]  0.0-60.2 sec   139 MBytes  19.4 Mbits/sec   7.609 ms 413698/512780 (81%)
[  3]  0.0-60.2 sec  79 datagrams received out-of-order

Ping from InstaGENI Chicago VM to InstaGENI GPO VM

60 packets transmitted, 60 received, 0% packet loss, time 59030ms
rtt min/avg/max/mdev = 33.110/38.146/167.147/22.095 ms