277 | | omni.py createslice IG-ST-3 |
278 | | stitcher.py createsliver IG-ST-3 IG-ST-3.rspec -o |
| 277 | $ stitcher.py createsliver IG-ST-3 IG-ST-3.rspec -o |
| 278 | 12:25:34 INFO : Configured logging from file /home/lnevers/gcf-2.9-pre1/src/gcf/stitcher_logging.conf |
| 279 | 12:25:35 INFO : Reading slice IG-ST-3 credential... |
| 280 | 12:25:35 INFO : Slice urn:publicid:IDN+ch.geni.net:ln-test+slice+IG-ST-3 expires on 2015-03-18 16:25:32 UTC |
| 281 | 12:25:35 INFO : Calling SCS... |
| 282 | 12:25:41 INFO : Multi-AM reservation will include resources from these aggregates: |
| 283 | 12:25:41 INFO : <Aggregate ukypks2-ig> |
| 284 | 12:25:41 INFO : <Aggregate gpo-ig> |
| 285 | 12:25:41 INFO : <Aggregate clemson-ig> |
| 286 | 12:25:41 INFO : <Aggregate al2s> |
| 287 | 12:25:41 INFO : <Aggregate ion> |
| 288 | 12:25:41 INFO : Stitcher doing createsliver at <Aggregate ukypks2-ig>... |
| 289 | 12:25:58 INFO : ... Allocation at <Aggregate ukypks2-ig> complete. |
| 290 | 12:25:58 INFO : Stitcher doing createsliver at <Aggregate gpo-ig>... |
| 291 | 12:26:18 INFO : ... Allocation at <Aggregate gpo-ig> complete. |
| 292 | 12:26:18 INFO : Stitcher doing createsliver at <Aggregate clemson-ig>... |
| 293 | 12:26:33 INFO : ... Allocation at <Aggregate clemson-ig> complete. |
| 294 | 12:26:34 INFO : Stitcher doing createsliver at <Aggregate al2s>... |
| 295 | 12:26:36 ERROR : {'output': 'Exception: requested VLAN unavailable: sdn-sw.atla.net.internet2.edu,eth15/1 VLAN=3995', 'code': {'geni_code': 24}} |
| 296 | 12:26:36 INFO : Will put <Aggregate al2s> back in the pool to allocate. Got: VLAN was unavailable. Retry <Aggregate al2s> 2nd time with <Hop u'urn:publicid:IDN+al2s.internet2.edu+interface+sdn-sw.atla.net.internet2.edu:eth15/1:*' on path u'link1'> new suggested 3962 (not 3995) |
| 297 | 12:26:36 INFO : Pausing for 30 seconds for Aggregates to free up resources... |
| 298 | |
| 299 | |
| 300 | 12:27:06 INFO : Stitcher doing createsliver at <Aggregate al2s>... |
| 301 | 12:27:11 INFO : ... Allocation at <Aggregate al2s> complete. |
| 302 | 12:27:11 INFO : Stitcher doing createsliver at <Aggregate ion>... |
| 303 | 12:27:57 INFO : DCN AM <Aggregate ion>: must wait for status ready.... |
| 304 | 12:27:57 INFO : Pausing 30 seconds to let circuit become ready... |
| 305 | 12:28:34 INFO : Pausing 30 seconds to let circuit become ready... |
| 306 | 12:29:12 WARNING : sliverstatus: 156111 is (still) failed at <Aggregate ion>. Delete and retry. |
| 307 | 12:29:12 WARNING : sliverstatus: 156121 is (still) failed at <Aggregate ion>. Delete and retry. |
| 308 | 12:29:12 WARNING : Status had error message: VLAN cancelled by rollback from contingent failure |
| 309 | 12:29:12 INFO : Doing deletesliver at <Aggregate ion>... |
| 310 | 12:29:17 WARNING : <Aggregate ion> says requested VLAN was unavailable at <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.atla:xe-0/3/0:al2s' on path u'link'> |
| 311 | 12:29:17 INFO : Will put <Aggregate ion> back in the pool to allocate. Got: VLAN was unavailable. Retry <Aggregate ion> 2nd time with <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.atla:xe-0/3/0:al2s' on path u'link'> new suggested 3988 (not 3940) |
| 312 | 12:29:17 INFO : Pausing for 600 seconds for Aggregates to free up resources... |
| 313 | |
| 314 | |
| 315 | 12:39:17 INFO : Stitcher doing createsliver at <Aggregate ion>... |
| 316 | 12:40:03 INFO : DCN AM <Aggregate ion>: must wait for status ready.... |
| 317 | 12:40:03 INFO : Pausing 30 seconds to let circuit become ready... |
| 318 | 12:40:40 INFO : Pausing 30 seconds to let circuit become ready... |
| 319 | 12:41:17 WARNING : sliverstatus: 156131 is (still) failed at <Aggregate ion>. Delete and retry. |
| 320 | 12:41:17 WARNING : sliverstatus: 156141 is (still) failed at <Aggregate ion>. Delete and retry. |
| 321 | 12:41:17 WARNING : Status had error message: VLAN cancelled by rollback from contingent failure |
| 322 | 12:41:17 INFO : Doing deletesliver at <Aggregate ion>... |
| 323 | 12:41:23 WARNING : <Aggregate ion> says requested VLAN was unavailable at <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.atla:xe-0/3/0:al2s' on path u'link'> |
| 324 | 12:41:23 INFO : Will put <Aggregate ion> back in the pool to allocate. Got: VLAN was unavailable. Retry <Aggregate ion> 3rd time with <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.atla:xe-0/3/0:al2s' on path u'link'> new suggested 3974 (not 3988) |
| 325 | 12:41:23 INFO : Pausing for 600 seconds for Aggregates to free up resources... |
| 326 | |
| 327 | |
| 328 | 12:51:23 INFO : Stitcher doing createsliver at <Aggregate ion>... |
| 329 | 12:52:25 INFO : DCN AM <Aggregate ion>: must wait for status ready.... |
| 330 | 12:52:25 INFO : Pausing 30 seconds to let circuit become ready... |
| 331 | 12:53:02 INFO : Pausing 30 seconds to let circuit become ready... |
| 332 | 12:53:39 WARNING : sliverstatus: 156171 is (still) failed at <Aggregate ion>. Delete and retry. |
| 333 | 12:53:39 WARNING : sliverstatus: 156181 is (still) failed at <Aggregate ion>. Delete and retry. |
| 334 | 12:53:39 WARNING : Status had error message: VLAN cancelled by rollback from contingent failure |
| 335 | 12:53:39 INFO : Doing deletesliver at <Aggregate ion>... |
| 336 | 12:53:45 WARNING : <Aggregate ion> says requested VLAN was unavailable at <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.atla:xe-0/3/0:al2s' on path u'link'> |
| 337 | 12:53:45 WARNING : Stitching failed but will retry: Circuit reservation failed at <Aggregate ion>. Try again from the SCS. (Error: Too many failures to find a VLAN tag (<Aggregate ion> reports selected VLAN is unavailable for <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.atla:xe-0/3/0:al2s' on path u'link'>: Sliver status for circuit 156171 was (still): failed: VLAN PCE(PCE_CREATE_FAILED): 'There are no VLANs available on link ion.internet2.edu:rtr.atla:xe-0/3/0:al2s on reservation ion.internet2.edu-156171 in VLAN PCE'. |
| 338 | Sliver status for circuit 156181 was (still): failed: VLAN cancelled by rollback from contingent failure)) |
| 339 | 12:53:45 INFO : Deleting existing reservations... |
| 340 | 12:53:45 INFO : Doing deletesliver at <Aggregate ukypks2-ig>... |
| 341 | 12:53:50 INFO : Deleted reservation at <Aggregate ukypks2-ig>. |
| 342 | 12:53:50 INFO : Doing deletesliver at <Aggregate gpo-ig>... |
| 343 | 12:53:52 INFO : Deleted reservation at <Aggregate gpo-ig>. |
| 344 | 12:53:52 INFO : Doing deletesliver at <Aggregate clemson-ig>... |
| 345 | 12:53:54 INFO : Deleted reservation at <Aggregate clemson-ig>. |
| 346 | 12:53:54 INFO : Doing deletesliver at <Aggregate al2s>... |
| 347 | 12:55:28 INFO : Deleted reservation at <Aggregate al2s>. |
| 348 | 12:55:28 INFO : Calling SCS for the 2nd time... |
| 349 | 12:55:32 INFO : Pausing for 600 seconds for Aggregates to free up resources... |
| 350 | |
| 351 | |
| 352 | 13:05:32 INFO : Multi-AM reservation will include resources from these aggregates: |
| 353 | 13:05:32 INFO : <Aggregate ukypks2-ig> |
| 354 | 13:05:32 INFO : <Aggregate gpo-ig> |
| 355 | 13:05:32 INFO : <Aggregate clemson-ig> |
| 356 | 13:05:32 INFO : <Aggregate al2s> |
| 357 | 13:05:32 INFO : <Aggregate ion> |
| 358 | 13:05:32 INFO : Stitcher doing createsliver at <Aggregate ukypks2-ig>... |
| 359 | 13:05:49 INFO : ... Allocation at <Aggregate ukypks2-ig> complete. |
| 360 | 13:05:49 INFO : Stitcher doing createsliver at <Aggregate gpo-ig>... |
| 361 | 13:06:04 INFO : ... Allocation at <Aggregate gpo-ig> complete. |
| 362 | 13:06:04 INFO : Stitcher doing createsliver at <Aggregate clemson-ig>... |
| 363 | 13:06:21 INFO : ... Allocation at <Aggregate clemson-ig> complete. |
| 364 | 13:06:21 INFO : Stitcher doing createsliver at <Aggregate al2s>... |
| 365 | 13:06:26 INFO : ... Allocation at <Aggregate al2s> complete. |
| 366 | 13:06:26 INFO : Stitcher doing createsliver at <Aggregate ion>... |
| 367 | 13:07:11 INFO : DCN AM <Aggregate ion>: must wait for status ready.... |
| 368 | 13:07:11 INFO : Pausing 30 seconds to let circuit become ready... |
| 369 | 13:07:48 INFO : Pausing 30 seconds to let circuit become ready... |
| 370 | 13:08:27 INFO : DCN circuit 156201 is ready at <Aggregate ion> |
| 371 | 13:08:27 INFO : DCN circuit 156191 is ready at <Aggregate ion> |
| 372 | 13:08:34 INFO : ... Allocation at <Aggregate ion> complete. |
| 373 | 13:08:34 INFO : All aggregates are complete. |
| 374 | 13:08:34 INFO : Your resources expire at 2015-03-17T16:55:32 (UTC). |
| 375 | 13:08:34 INFO : Saved combined reservation RSpec at 5 AMs to file '/home/lnevers/gcf-test/stitch-test/Clemson/IG-ST-3-manifest-rspec-multiam-combined.xml' |
| 376 | Success: Reserved resources in slice IG-ST-3 at 5 Aggregates (including 2 intermediate aggregate(s) not in the original request), creating 2 stitched link(s). |