601 | | 12:42:40 INFO : Configured logging from file /home/lnevers/gcf-2.8/src/gcf/stitcher_logging.conf |
602 | | 12:42:41 INFO : Reading slice IG-ST-6 credential... |
603 | | 12:42:41 INFO : Slice urn:publicid:IDN+ch.geni.net:ln-test+slice+IG-ST-6 expires on 2015-02-14 00:00:00 UTC |
604 | | 12:42:41 INFO : Calling SCS... |
605 | | 12:42:43 INFO : Multi-AM reservation will include resources from these aggregates: |
606 | | 12:42:43 INFO : <Aggregate utc-ig> |
607 | | 12:42:43 INFO : <Aggregate gpo-ig> |
608 | | 12:42:43 INFO : <Aggregate al2s> |
609 | | 12:42:43 INFO : <Aggregate ion> |
610 | | 12:42:43 INFO : Stitcher doing createsliver at <Aggregate utc-ig>... |
611 | | 12:43:02 INFO : ... Allocation at <Aggregate utc-ig> complete. |
612 | | 12:43:02 INFO : Stitcher doing createsliver at <Aggregate gpo-ig>... |
613 | | 12:43:20 INFO : ... Allocation at <Aggregate gpo-ig> complete. |
614 | | 12:43:20 INFO : Stitcher doing createsliver at <Aggregate al2s>... |
615 | | 12:43:23 INFO : ... Allocation at <Aggregate al2s> complete. |
616 | | 12:43:23 INFO : Stitcher doing createsliver at <Aggregate ion>... |
617 | | 12:44:08 INFO : DCN AM <Aggregate ion>: must wait for status ready.... |
618 | | 12:44:08 INFO : Pausing 30 seconds to let circuit become ready... |
619 | | 12:44:46 WARNING : sliverstatus: 153381 is (still) failed at <Aggregate ion>. Delete and retry. |
620 | | 12:44:46 INFO : Doing deletesliver at <Aggregate ion>... |
621 | | 12:44:51 WARNING : <Aggregate ion> says requested VLAN was unavailable at <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.newy:et-5/0/0:gpo-ig' on path u'link'> |
622 | | 12:44:51 INFO : Deleting some reservations to retry, avoiding failed VLAN... |
623 | | 12:44:51 INFO : Doing deletesliver at <Aggregate gpo-ig>... |
624 | | 12:46:19 ERROR : {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+c905a6d42e2a9596f6f4dede975404b4', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=c905a6d42e2a9596f6f4dede975404b4'}, 'value': 0} |
625 | | 12:46:29 INFO : ... aggregate was busy, will retry ... |
626 | | 12:47:55 ERROR : {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+b1789155aeffdf7e55575110db6c16fe', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=b1789155aeffdf7e55575110db6c16fe'}, 'value': 0} |
627 | | 12:48:05 INFO : ... aggregate was busy, will retry ... |
628 | | 12:49:32 ERROR : {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+e11a0e054523dcf46194b90e5111a024', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=e11a0e054523dcf46194b90e5111a024'}, 'value': 0} |
629 | | 12:49:42 INFO : ... aggregate was busy, will retry ... |
630 | | 12:51:12 INFO : ... done. |
631 | | 12:51:12 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>.... |
632 | | 12:51:12 INFO : Pausing for 30 seconds for Aggregates to free up resources... |
633 | | |
634 | | |
635 | | 12:51:42 INFO : Checking that prior reservation at <Aggregate gpo-ig> has been cleared up.... |
636 | | 12:51:44 ERROR : {'output': 'No slice or aggregate here', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+a1b7067f79f550672d0b9cbd55257b19', 'am_type': 'protogeni', 'geni_code': 12, 'am_code': 12, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=a1b7067f79f550672d0b9cbd55257b19'}, 'value': 0} |
637 | | 12:51:45 INFO : ... it is, so can try a new reservation. |
638 | | 12:51:45 INFO : Stitcher doing createsliver at <Aggregate gpo-ig>... |
639 | | 12:52:23 INFO : ... Allocation at <Aggregate gpo-ig> complete. |
640 | | 12:52:23 INFO : Stitcher doing createsliver at <Aggregate ion>... |
641 | | 12:53:08 INFO : DCN AM <Aggregate ion>: must wait for status ready.... |
642 | | 12:53:08 INFO : Pausing 30 seconds to let circuit become ready... |
643 | | 12:53:46 INFO : DCN circuit 153391 is ready at <Aggregate ion> |
644 | | 12:53:53 INFO : ... Allocation at <Aggregate ion> complete. |
645 | | 12:53:53 INFO : All aggregates are complete. |
646 | | 12:53:53 INFO : Your resources expire at 2015-02-13T17:32:43 (UTC). |
647 | | 12:53:53 INFO : Saved combined reservation RSpec at 4 AMs to file '/home/lnevers/gcf-test/stitch-test/UTC/IG-ST-6-manifest-rspec-multiam-combined.xml' |
| 601 | 13:15:24 INFO : Configured logging from file /home/lnevers/gcf-2.8/src/gcf/stitcher_logging.conf |
| 602 | 13:15:25 INFO : Reading slice IG-ST-6 credential... |
| 603 | 13:15:25 INFO : Slice urn:publicid:IDN+ch.geni.net:ln-test+slice+IG-ST-6 expires on 2015-02-14 00:00:00 UTC |
| 604 | 13:15:25 INFO : Calling SCS... |
| 605 | 13:15:27 INFO : Multi-AM reservation will include resources from these aggregates: |
| 606 | 13:15:27 INFO : <Aggregate utc-ig> |
| 607 | 13:15:27 INFO : <Aggregate gpo-ig> |
| 608 | 13:15:27 INFO : <Aggregate al2s> |
| 609 | 13:15:27 INFO : <Aggregate ion> |
| 610 | 13:15:27 INFO : Stitcher doing createsliver at <Aggregate utc-ig>... |
| 611 | 13:15:43 INFO : ... Allocation at <Aggregate utc-ig> complete. |
| 612 | 13:15:43 INFO : Stitcher doing createsliver at <Aggregate gpo-ig>... |
| 613 | 13:15:59 INFO : ... Allocation at <Aggregate gpo-ig> complete. |
| 614 | 13:15:59 INFO : Stitcher doing createsliver at <Aggregate al2s>... |
| 615 | 13:16:02 INFO : ... Allocation at <Aggregate al2s> complete. |
| 616 | 13:16:02 INFO : Stitcher doing createsliver at <Aggregate ion>... |
| 617 | 13:16:47 INFO : DCN AM <Aggregate ion>: must wait for status ready.... |
| 618 | 13:16:47 INFO : Pausing 30 seconds to let circuit become ready... |
| 619 | 13:17:25 WARNING : sliverstatus: 153401 is (still) failed at <Aggregate ion>. Delete and retry. |
| 620 | 13:17:25 INFO : Doing deletesliver at <Aggregate ion>... |
| 621 | 13:17:30 WARNING : <Aggregate ion> says requested VLAN was unavailable at <Hop u'urn:publicid:IDN+ion.internet2.edu+interface+rtr.newy:et-5/0/0:gpo-ig' on path u'link'> |
| 622 | 13:17:30 INFO : Deleting some reservations to retry, avoiding failed VLAN... |
| 623 | 13:17:30 INFO : Doing deletesliver at <Aggregate gpo-ig>... |
| 624 | 13:18:56 ERROR : {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+21a926163fe00f8af0dac119a5a8ddf2', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=21a926163fe00f8af0dac119a5a8ddf2'}, 'value': 0} |
| 625 | 13:19:06 INFO : ... aggregate was busy, will retry ... |
| 626 | 13:20:36 ERROR : {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+edba31bffa1ceec97db4fd88fc1d8ee0', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=edba31bffa1ceec97db4fd88fc1d8ee0'}, 'value': 0} |
| 627 | 13:20:46 INFO : ... aggregate was busy, will retry ... |
| 628 | 13:22:13 ERROR : {'output': 'start/restart in progress; try again later', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+57f24bde8b5e708252b19f744f8ef19d', 'am_type': 'protogeni', 'geni_code': 14, 'am_code': 14, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=57f24bde8b5e708252b19f744f8ef19d'}, 'value': 0} |
| 629 | 13:22:23 INFO : ... aggregate was busy, will retry ... |
| 630 | 13:23:29 INFO : ... done. |
| 631 | 13:23:29 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>.... |
| 632 | 13:23:29 INFO : Pausing for 30 seconds for Aggregates to free up resources... |
| 633 | |
| 634 | |
| 635 | 13:23:59 INFO : Checking that prior reservation at <Aggregate gpo-ig> has been cleared up.... |
| 636 | 13:24:00 ERROR : {'output': 'No slice or aggregate here', 'code': {'protogeni_error_log': 'urn:publicid:IDN+instageni.gpolab.bbn.com+log+c15fcaa28e576d5c77be7edc426334d3', 'am_type': 'protogeni', 'geni_code': 12, 'am_code': 12, 'protogeni_error_url': 'https://boss.instageni.gpolab.bbn.com/spewlogfile.php3?logfile=c15fcaa28e576d5c77be7edc426334d3'}, 'value': 0} |
| 637 | 13:24:00 INFO : ... it is, so can try a new reservation. |
| 638 | 13:24:00 INFO : Stitcher doing createsliver at <Aggregate gpo-ig>... |
| 639 | 13:24:39 INFO : ... Allocation at <Aggregate gpo-ig> complete. |
| 640 | 13:24:39 INFO : Stitcher doing createsliver at <Aggregate ion>... |
| 641 | 13:25:24 INFO : DCN AM <Aggregate ion>: must wait for status ready.... |
| 642 | 13:25:24 INFO : Pausing 30 seconds to let circuit become ready... |
| 643 | 13:26:01 INFO : DCN circuit 153411 is ready at <Aggregate ion> |
| 644 | 13:26:08 INFO : ... Allocation at <Aggregate ion> complete. |
| 645 | 13:26:08 INFO : All aggregates are complete. |
| 646 | 13:26:08 INFO : Your resources expire at 2015-02-13T18:05:27 (UTC). |
| 647 | 13:26:08 INFO : Saved combined reservation RSpec at 4 AMs to file '/home/lnevers/gcf-test/stitch-test/UTC/IG-ST-6-manifest-rspec-multiam-combined.xml' |