Testing PullReq against Topology Tests

Build: #395 failed

Job: TopoTest 4.0 Branch failed

Build log

The build generated 8,067 lines of output.The output is too long and has been truncated to the last 1,000 lines. Download or view full build log

21-Apr-2019 14:07:07 2019-04-21 23:07:07,912 INFO: Comparing router "r3" "show mpls ldp binding json" output
21-Apr-2019 14:07:07 2019-04-21 23:07:07,912 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:07 2019-04-21 23:07:07,998 INFO: 'router_json_cmp' succeeded after 0.09 seconds
21-Apr-2019 14:07:08 PASSED
21-Apr-2019 14:07:08 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_pwid_bindings 2019-04-21 23:07:08,000 INFO: Test: verify LDP PW-ID bindings
21-Apr-2019 14:07:08 2019-04-21 23:07:08,509 INFO: Comparing router "r1" "show l2vpn atom binding json" output
21-Apr-2019 14:07:08 2019-04-21 23:07:08,509 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:08 2019-04-21 23:07:08,583 INFO: 'router_json_cmp' succeeded after 0.07 seconds
21-Apr-2019 14:07:08 2019-04-21 23:07:08,583 INFO: Comparing router "r2" "show l2vpn atom binding json" output
21-Apr-2019 14:07:08 2019-04-21 23:07:08,583 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:08 2019-04-21 23:07:08,656 INFO: 'router_json_cmp' succeeded after 0.07 seconds
21-Apr-2019 14:07:08 2019-04-21 23:07:08,657 INFO: Comparing router "r3" "show l2vpn atom binding json" output
21-Apr-2019 14:07:08 2019-04-21 23:07:08,657 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:08 2019-04-21 23:07:08,731 INFO: 'router_json_cmp' succeeded after 0.07 seconds
21-Apr-2019 14:07:08 PASSED
21-Apr-2019 14:07:08 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_pseudowires 2019-04-21 23:07:08,733 INFO: Test: verify LDP pseudowires
21-Apr-2019 14:07:09 2019-04-21 23:07:09,199 INFO: Comparing router "r1" "show l2vpn atom vc json" output
21-Apr-2019 14:07:09 2019-04-21 23:07:09,199 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:09 2019-04-21 23:07:09,278 INFO: 'router_json_cmp' succeeded after 0.08 seconds
21-Apr-2019 14:07:09 2019-04-21 23:07:09,278 INFO: Comparing router "r2" "show l2vpn atom vc json" output
21-Apr-2019 14:07:09 2019-04-21 23:07:09,278 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:09 2019-04-21 23:07:09,359 INFO: 'router_json_cmp' succeeded after 0.08 seconds
21-Apr-2019 14:07:09 2019-04-21 23:07:09,359 INFO: Comparing router "r3" "show l2vpn atom vc json" output
21-Apr-2019 14:07:09 2019-04-21 23:07:09,359 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:09 2019-04-21 23:07:09,435 INFO: 'router_json_cmp' succeeded after 0.08 seconds
21-Apr-2019 14:07:09 PASSED
21-Apr-2019 14:07:09 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_pseudowires_after_link_down 2019-04-21 23:07:09,438 INFO: Test: verify LDP pseudowires after r1-r2 link goes down
21-Apr-2019 14:07:09 2019-04-21 23:07:09,897 INFO: setting node "s4" link "s4-eth0" to state "down"
21-Apr-2019 14:07:09 2019-04-21 23:07:09,905 INFO: Comparing router "r1" "show l2vpn atom vc json" output
21-Apr-2019 14:07:09 2019-04-21 23:07:09,905 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:10 2019-04-21 23:07:10,012 INFO: 'router_json_cmp' succeeded after 0.11 seconds
21-Apr-2019 14:07:10 2019-04-21 23:07:10,012 INFO: Comparing router "r2" "show l2vpn atom vc json" output
21-Apr-2019 14:07:10 2019-04-21 23:07:10,013 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:10 2019-04-21 23:07:10,092 INFO: 'router_json_cmp' succeeded after 0.08 seconds
21-Apr-2019 14:07:10 2019-04-21 23:07:10,092 INFO: Comparing router "r3" "show l2vpn atom vc json" output
21-Apr-2019 14:07:10 2019-04-21 23:07:10,092 INFO: 'router_json_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:07:10 2019-04-21 23:07:10,170 INFO: 'router_json_cmp' succeeded after 0.08 seconds
21-Apr-2019 14:07:10 PASSED
21-Apr-2019 14:07:11 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_memory_leak 2019-04-21 23:07:11,090 INFO: r1: stopping ldpd
21-Apr-2019 14:07:11 2019-04-21 23:07:11,095 INFO: r1: stopping ospfd
21-Apr-2019 14:07:11 2019-04-21 23:07:11,097 INFO: r1: stopping zebra
21-Apr-2019 14:07:11 2019-04-21 23:07:11,098 INFO: r1: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:07:13
21-Apr-2019 14:07:13 r1: zebra crashed. Core file found - Backtrace follows:
21-Apr-2019 14:07:13 [New LWP 30746]
21-Apr-2019 14:07:13 [Thread debugging using libthread_db enabled]
21-Apr-2019 14:07:13 Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
21-Apr-2019 14:07:13 Core was generated by `/usr/lib/frr/zebra'.
21-Apr-2019 14:07:13 Program terminated with signal SIGABRT, Aborted.
21-Apr-2019 14:07:13 #0  0x00007f8c49031428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:07:13 #0  0x00007f8c49031428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:07:13 #1  0x00007f8c4903302a in __GI_abort () at abort.c:89
21-Apr-2019 14:07:13 #2  0x00007f8c49a30354 in _zlog_assert_failed (assertion=assertion@entry=0x55561ca29782 "zvrf", file=file@entry=0x55561ca2976f "zebra/zebra_mpls.c", line=line@entry=961, function=function@entry=0x55561ca2a060 <__func__.15728> "lsp_processq_del") at lib/log.c:710
21-Apr-2019 14:07:13 #3  0x000055561c9f3d6a in lsp_processq_del (wq=<optimized out>, data=0x55561e298770) at zebra/zebra_mpls.c:961
21-Apr-2019 14:07:13 #4  0x00007f8c49a55eee in work_queue_item_remove (wq=0x55561dda67b0, item=0x55561ddb7430) at lib/workqueue.c:67
21-Apr-2019 14:07:13 #5  0x00007f8c49a56375 in work_queue_free (wq=0x55561dda67b0) at lib/workqueue.c:112
21-Apr-2019 14:07:13 #6  0x000055561c9e90b7 in sigint () at zebra/main.c:152
21-Apr-2019 14:07:13 #7  0x00007f8c49a433e8 in quagga_sigevent_process () at lib/sigevent.c:103
21-Apr-2019 14:07:13 #8  0x00007f8c49a4f64d in thread_fetch (m=m@entry=0x55561dbef5d0, fetch=fetch@entry=0x7ffd8115f430) at lib/thread.c:1333
21-Apr-2019 14:07:13 #9  0x00007f8c49a2d9a3 in frr_run (master=0x55561dbef5d0) at lib/libfrr.c:878
21-Apr-2019 14:07:13 #10 0x000055561c9dcb5d in main (argc=1, argv=0x7ffd8115f718) at zebra/main.c:366
21-Apr-2019 14:07:13 2019-04-21 23:07:13,568 INFO:
21-Apr-2019 14:07:13 Router r1 zebra StdErr Log:
21-Apr-2019 14:07:13 log: showing active allocations in memory group libfrr
21-Apr-2019 14:07:13 log: memstats:  Host config                   :      3 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Command Tokens                :   3314 *         72
21-Apr-2019 14:07:13 log: memstats:  Command Token Text            :   2464 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Command Token Help            :   2464 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Command Argument Name         :    613 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Graph                         :     24 *          8
21-Apr-2019 14:07:13 log: memstats:  Graph Node                    :   3895 *         32
21-Apr-2019 14:07:13 log: memstats:  Hash                          :     52 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Hash Bucket                   :    590 *         32
21-Apr-2019 14:07:13 log: memstats:  Hash Index                    :     26 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Hook entry                    :      4 *         48
21-Apr-2019 14:07:13 log: memstats:  Link List                     :     10 *         40
21-Apr-2019 14:07:13 log: memstats:  Link Node                     :     38 *         24
21-Apr-2019 14:07:13 log: memstats:  Logging                       :      2 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Temporary memory              :      1 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Nexthop                       :      2 *        112
21-Apr-2019 14:07:13 log: memstats:  Nexthop label                 :      2 *          8
21-Apr-2019 14:07:13 log: memstats:  Logical-Router                :      1 *         72
21-Apr-2019 14:07:13 log: memstats:  Logical-Router Name           :      1 *         18
21-Apr-2019 14:07:13 log: memstats:  Priority queue                :      1 *         32
21-Apr-2019 14:07:13 log: memstats:  Priority queue data           :      1 *        256
21-Apr-2019 14:07:13 log: memstats:  Privilege information         :      2 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Thread                        :     16 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Thread master                 :      3 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Thread stats                  :      9 *         64
21-Apr-2019 14:07:13 log: memstats:  Vector                        :   7841 *         16
21-Apr-2019 14:07:13 log: memstats:  Vector index                  :   7841 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Work queue                    :      2 * (variably sized)
21-Apr-2019 14:07:13 log: memstats:  Work queue item               :      2 *         24
21-Apr-2019 14:07:13 log: memstats:  Work queue name string        :      1 * (variably sized)
21-Apr-2019 14:07:13 log: showing active allocations in memory group Label Manager
21-Apr-2019 14:07:13 log: memstats:  Label Manager Chunk           :      2 *         16
21-Apr-2019 14:07:13 log: showing active allocations in memory group zebra
21-Apr-2019 14:07:13 log: memstats:  MPLS LSP object               :      2 *         40
21-Apr-2019 14:07:13 log: memstats:  MPLS nexthop object           :      2 *         56
21-Apr-2019 14:07:13 log: memstats:  Zebra Name Space              :      1 *        264
21-Apr-2019 14:07:13
21-Apr-2019 14:07:13 2019-04-21 23:07:13,574 INFO: r2: stopping ldpd
21-Apr-2019 14:07:13 2019-04-21 23:07:13,580 INFO: r2: stopping ospfd
21-Apr-2019 14:07:13 2019-04-21 23:07:13,585 INFO: r2: stopping zebra
21-Apr-2019 14:07:13 2019-04-21 23:07:13,585 INFO: r2: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:07:15
21-Apr-2019 14:07:15 r2: zebra crashed. Core file found - Backtrace follows:
21-Apr-2019 14:07:15 [New LWP 30796]
21-Apr-2019 14:07:15 [Thread debugging using libthread_db enabled]
21-Apr-2019 14:07:15 Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
21-Apr-2019 14:07:15 Core was generated by `/usr/lib/frr/zebra'.
21-Apr-2019 14:07:15 Program terminated with signal SIGABRT, Aborted.
21-Apr-2019 14:07:15 #0  0x00007f4902428428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:07:15 #0  0x00007f4902428428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:07:15 #1  0x00007f490242a02a in __GI_abort () at abort.c:89
21-Apr-2019 14:07:15 #2  0x00007f4902e27354 in _zlog_assert_failed (assertion=assertion@entry=0x5582d4bdf782 "zvrf", file=file@entry=0x5582d4bdf76f "zebra/zebra_mpls.c", line=line@entry=961, function=function@entry=0x5582d4be0060 <__func__.15728> "lsp_processq_del") at lib/log.c:710
21-Apr-2019 14:07:15 #3  0x00005582d4ba9d6a in lsp_processq_del (wq=<optimized out>, data=0x5582d6eea7b0) at zebra/zebra_mpls.c:961
21-Apr-2019 14:07:15 #4  0x00007f4902e4ceee in work_queue_item_remove (wq=0x5582d6ed97b0, item=0x5582d6eeb780) at lib/workqueue.c:67
21-Apr-2019 14:07:15 #5  0x00007f4902e4d375 in work_queue_free (wq=0x5582d6ed97b0) at lib/workqueue.c:112
21-Apr-2019 14:07:15 #6  0x00005582d4b9f0b7 in sigint () at zebra/main.c:152
21-Apr-2019 14:07:15 #7  0x00007f4902e3a3e8 in quagga_sigevent_process () at lib/sigevent.c:103
21-Apr-2019 14:07:15 #8  0x00007f4902e4664d in thread_fetch (m=m@entry=0x5582d6d225d0, fetch=fetch@entry=0x7ffc44d61b60) at lib/thread.c:1333
21-Apr-2019 14:07:15 #9  0x00007f4902e249a3 in frr_run (master=0x5582d6d225d0) at lib/libfrr.c:878
21-Apr-2019 14:07:15 #10 0x00005582d4b92b5d in main (argc=1, argv=0x7ffc44d61e48) at zebra/main.c:366
21-Apr-2019 14:07:16 2019-04-21 23:07:16,002 INFO:
21-Apr-2019 14:07:16 Router r2 zebra StdErr Log:
21-Apr-2019 14:07:16 log: showing active allocations in memory group libfrr
21-Apr-2019 14:07:16 log: memstats:  Host config                   :      3 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Command Tokens                :   3314 *         72
21-Apr-2019 14:07:16 log: memstats:  Command Token Text            :   2464 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Command Token Help            :   2464 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Command Argument Name         :    613 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Graph                         :     24 *          8
21-Apr-2019 14:07:16 log: memstats:  Graph Node                    :   3895 *         32
21-Apr-2019 14:07:16 log: memstats:  Hash                          :     52 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Hash Bucket                   :    590 *         32
21-Apr-2019 14:07:16 log: memstats:  Hash Index                    :     26 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Hook entry                    :      4 *         48
21-Apr-2019 14:07:16 log: memstats:  Link List                     :     10 *         40
21-Apr-2019 14:07:16 log: memstats:  Link Node                     :     38 *         24
21-Apr-2019 14:07:16 log: memstats:  Logging                       :      2 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Temporary memory              :      1 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Nexthop                       :      1 *        112
21-Apr-2019 14:07:16 log: memstats:  Nexthop label                 :      1 *          8
21-Apr-2019 14:07:16 log: memstats:  Logical-Router                :      1 *         72
21-Apr-2019 14:07:16 log: memstats:  Logical-Router Name           :      1 *         18
21-Apr-2019 14:07:16 log: memstats:  Priority queue                :      1 *         32
21-Apr-2019 14:07:16 log: memstats:  Priority queue data           :      1 *        256
21-Apr-2019 14:07:16 log: memstats:  Privilege information         :      2 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Thread                        :     16 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Thread master                 :      3 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Thread stats                  :      9 *         64
21-Apr-2019 14:07:16 log: memstats:  Vector                        :   7841 *         16
21-Apr-2019 14:07:16 log: memstats:  Vector index                  :   7841 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Work queue                    :      2 * (variably sized)
21-Apr-2019 14:07:16 log: memstats:  Work queue item               :      1 *         24
21-Apr-2019 14:07:16 log: memstats:  Work queue name string        :      1 * (variably sized)
21-Apr-2019 14:07:16 log: showing active allocations in memory group Label Manager
21-Apr-2019 14:07:16 log: memstats:  Label Manager Chunk           :      2 *         16
21-Apr-2019 14:07:16 log: showing active allocations in memory group zebra
21-Apr-2019 14:07:16 log: memstats:  MPLS LSP object               :      1 *         40
21-Apr-2019 14:07:16 log: memstats:  MPLS nexthop object           :      1 *         56
21-Apr-2019 14:07:16 log: memstats:  Zebra Name Space              :      1 *        264
21-Apr-2019 14:07:16
21-Apr-2019 14:07:16 2019-04-21 23:07:16,005 INFO: r3: stopping ldpd
21-Apr-2019 14:07:16 2019-04-21 23:07:16,008 INFO: r3: stopping ospfd
21-Apr-2019 14:07:16 2019-04-21 23:07:16,012 INFO: r3: stopping zebra
21-Apr-2019 14:07:16 2019-04-21 23:07:16,012 INFO: r3: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:07:18 2019-04-21 23:07:18,044 INFO: ce3: stopping zebra
21-Apr-2019 14:07:18 2019-04-21 23:07:18,047 INFO: ce3: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:07:20 2019-04-21 23:07:20,065 INFO: ce2: stopping zebra
21-Apr-2019 14:07:20 2019-04-21 23:07:20,070 INFO: ce2: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:07:22 2019-04-21 23:07:22,085 INFO: ce1: stopping zebra
21-Apr-2019 14:07:22 PASSED2019-04-21 23:07:22,099 INFO: stopping topology: test_ldp_vpls_topo1
21-Apr-2019 14:07:22 2019-04-21 23:07:22,107 INFO: stopping "s3"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,107 INFO: stopping "s2"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,107 INFO: stopping "s1"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,107 INFO: stopping "s6"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,108 INFO: stopping "s5"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,108 INFO: stopping "s4"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,123 INFO: stopping "s3"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,123 INFO: stopping "s2"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,123 INFO: stopping "s1"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,123 INFO: stopping "s6"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,123 INFO: stopping "s5"
21-Apr-2019 14:07:22 2019-04-21 23:07:22,123 INFO: stopping "s4"
21-Apr-2019 14:07:23
21-Apr-2019 14:07:24 *** defaultIntf: warning: lm has no interfaces
21-Apr-2019 14:07:24 lm-proxy-topo1/test_lm-proxy-topo1.py::test_lm_proxy 2019-04-21 23:07:24,951 INFO: loading topology: test_lm-proxy-topo1
21-Apr-2019 14:07:24 2019-04-21 23:07:24,951 INFO: starting topology: test_lm-proxy-topo1
21-Apr-2019 14:07:25 2019-04-21 23:07:25,014 INFO: assert skipped at "test_lm-proxy-topo1/test_lm_proxy": Skipping test: no VRF support
21-Apr-2019 14:07:25 SKIPPED
21-Apr-2019 14:07:25 ospf-sr-topo1/test_ospf_sr_topo1.py::test_ospf_sr 2019-04-21 23:07:25,019 INFO:
21-Apr-2019 14:07:25
21-Apr-2019 14:07:25 ---- Starting OSPF Segment Routing tests ----
21-Apr-2019 14:07:25
21-Apr-2019 14:07:26 2019-04-21 23:07:26,786 INFO: loading topology: test_ospf_sr_topo1
21-Apr-2019 14:07:26 2019-04-21 23:07:26,786 INFO: starting topology: test_ospf_sr_topo1
21-Apr-2019 14:07:26 2019-04-21 23:07:26,865 INFO: r4: running version: 4.0
21-Apr-2019 14:07:26 2019-04-21 23:07:26,866 INFO: r4: waiting for zebra to start (1 seconds)
21-Apr-2019 14:07:28 2019-04-21 23:07:28,076 INFO: r1: running version: 4.0
21-Apr-2019 14:07:28 2019-04-21 23:07:28,076 INFO: r1: waiting for zebra to start (1 seconds)
21-Apr-2019 14:07:29 2019-04-21 23:07:29,281 INFO: r2: running version: 4.0
21-Apr-2019 14:07:29 2019-04-21 23:07:29,282 INFO: r2: waiting for zebra to start (1 seconds)
21-Apr-2019 14:07:30 2019-04-21 23:07:30,506 INFO: r3: running version: 4.0
21-Apr-2019 14:07:30 2019-04-21 23:07:30,507 INFO: r3: waiting for zebra to start (1 seconds)
21-Apr-2019 14:07:32 2019-04-21 23:07:32,319 INFO: --- test OSPF Segment Routing Data Base ---
21-Apr-2019 14:07:32 2019-04-21 23:07:32,319 INFO:         Router "r1"
21-Apr-2019 14:07:32 2019-04-21 23:07:32,320 INFO: 'compare_ospf_srdb' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:08:21 2019-04-21 23:08:21,840 INFO: 'compare_ospf_srdb' succeeded after 49.52 seconds
21-Apr-2019 14:08:21 2019-04-21 23:08:21,841 INFO:         Router "r2"
21-Apr-2019 14:08:21 2019-04-21 23:08:21,841 INFO: 'compare_ospf_srdb' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:08:21 2019-04-21 23:08:21,949 INFO: 'compare_ospf_srdb' succeeded after 0.11 seconds
21-Apr-2019 14:08:21 2019-04-21 23:08:21,950 INFO:         Router "r3"
21-Apr-2019 14:08:21 2019-04-21 23:08:21,950 INFO: 'compare_ospf_srdb' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:08:22 2019-04-21 23:08:22,031 INFO: 'compare_ospf_srdb' succeeded after 0.08 seconds
21-Apr-2019 14:08:22 2019-04-21 23:08:22,031 INFO:         Router "r4"
21-Apr-2019 14:08:22 2019-04-21 23:08:22,031 INFO: 'compare_ospf_srdb' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:08:22 2019-04-21 23:08:22,117 INFO: 'compare_ospf_srdb' succeeded after 0.09 seconds
21-Apr-2019 14:08:22 PASSED
21-Apr-2019 14:08:22 ospf-sr-topo1/test_ospf_sr_topo1.py::test_ospf_kernel_route 2019-04-21 23:08:22,447 INFO: --- test OSPF Segment Routing MPLS tables ---
21-Apr-2019 14:08:22 2019-04-21 23:08:22,447 INFO:         Router "r1"
21-Apr-2019 14:08:22 2019-04-21 23:08:22,448 INFO: 'compare_mpls_table' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:08:22 2019-04-21 23:08:22,532 INFO: 'compare_mpls_table' succeeded after 0.08 seconds
21-Apr-2019 14:08:22 2019-04-21 23:08:22,533 INFO:         Router "r2"
21-Apr-2019 14:08:22 2019-04-21 23:08:22,533 INFO: 'compare_mpls_table' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:08:22 2019-04-21 23:08:22,614 INFO: 'compare_mpls_table' succeeded after 0.08 seconds
21-Apr-2019 14:08:22 2019-04-21 23:08:22,614 INFO:         Router "r3"
21-Apr-2019 14:08:22 2019-04-21 23:08:22,614 INFO: 'compare_mpls_table' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:08:22 2019-04-21 23:08:22,694 INFO: 'compare_mpls_table' succeeded after 0.08 seconds
21-Apr-2019 14:08:22 2019-04-21 23:08:22,694 INFO:         Router "r4"
21-Apr-2019 14:08:22 2019-04-21 23:08:22,694 INFO: 'compare_mpls_table' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:08:22 2019-04-21 23:08:22,774 INFO: 'compare_mpls_table' succeeded after 0.08 seconds
21-Apr-2019 14:08:22 PASSED
21-Apr-2019 14:08:23 ospf-sr-topo1/test_ospf_sr_topo1.py::test_memory_leak 2019-04-21 23:08:23,480 INFO: r4: stopping ospfd
21-Apr-2019 14:08:23 2019-04-21 23:08:23,485 INFO: r4: stopping zebra
21-Apr-2019 14:08:23 2019-04-21 23:08:23,485 INFO: r4: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:08:25
21-Apr-2019 14:08:25 r4: zebra crashed. Core file found - Backtrace follows:
21-Apr-2019 14:08:25 [New LWP 32642]
21-Apr-2019 14:08:25 [Thread debugging using libthread_db enabled]
21-Apr-2019 14:08:25 Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
21-Apr-2019 14:08:25 Core was generated by `/usr/lib/frr/zebra'.
21-Apr-2019 14:08:25 Program terminated with signal SIGABRT, Aborted.
21-Apr-2019 14:08:25 #0  0x00007fb9ce0b6428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:08:25 #0  0x00007fb9ce0b6428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:08:25 #1  0x00007fb9ce0b802a in __GI_abort () at abort.c:89
21-Apr-2019 14:08:25 #2  0x00007fb9ceab5354 in _zlog_assert_failed (assertion=assertion@entry=0x5650b8d66782 "zvrf", file=file@entry=0x5650b8d6676f "zebra/zebra_mpls.c", line=line@entry=961, function=function@entry=0x5650b8d67060 <__func__.15728> "lsp_processq_del") at lib/log.c:710
21-Apr-2019 14:08:25 #3  0x00005650b8d30d6a in lsp_processq_del (wq=<optimized out>, data=0x5650b93800a0) at zebra/zebra_mpls.c:961
21-Apr-2019 14:08:25 #4  0x00007fb9ceadaeee in work_queue_item_remove (wq=0x5650b91cec60, item=0x5650b937fb40) at lib/workqueue.c:67
21-Apr-2019 14:08:25 #5  0x00007fb9ceadb375 in work_queue_free (wq=0x5650b91cec60) at lib/workqueue.c:112
21-Apr-2019 14:08:25 #6  0x00005650b8d260b7 in sigint () at zebra/main.c:152
21-Apr-2019 14:08:25 #7  0x00007fb9ceac83e8 in quagga_sigevent_process () at lib/sigevent.c:103
21-Apr-2019 14:08:25 #8  0x00007fb9cead464d in thread_fetch (m=m@entry=0x5650b90195d0, fetch=fetch@entry=0x7ffd1ad8c5c0) at lib/thread.c:1333
21-Apr-2019 14:08:25 #9  0x00007fb9ceab29a3 in frr_run (master=0x5650b90195d0) at lib/libfrr.c:878
21-Apr-2019 14:08:25 #10 0x00005650b8d19b5d in main (argc=1, argv=0x7ffd1ad8c8a8) at zebra/main.c:366
21-Apr-2019 14:08:25 2019-04-21 23:08:25,912 INFO:
21-Apr-2019 14:08:25 Router r4 zebra StdErr Log:
21-Apr-2019 14:08:25 log: showing active allocations in memory group libfrr
21-Apr-2019 14:08:25 log: memstats:  Host config                   :      3 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Command Tokens                :   3314 *         72
21-Apr-2019 14:08:25 log: memstats:  Command Token Text            :   2464 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Command Token Help            :   2464 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Command Argument Name         :    613 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Graph                         :     24 *          8
21-Apr-2019 14:08:25 log: memstats:  Graph Node                    :   3895 *         32
21-Apr-2019 14:08:25 log: memstats:  Hash                          :     52 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Hash Bucket                   :    590 *         32
21-Apr-2019 14:08:25 log: memstats:  Hash Index                    :     26 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Hook entry                    :      4 *         48
21-Apr-2019 14:08:25 log: memstats:  Link List                     :     10 *         40
21-Apr-2019 14:08:25 log: memstats:  Link Node                     :     36 *         24
21-Apr-2019 14:08:25 log: memstats:  Logging                       :      2 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Temporary memory              :      1 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Nexthop                       :      6 *        112
21-Apr-2019 14:08:25 log: memstats:  Nexthop label                 :      6 *          8
21-Apr-2019 14:08:25 log: memstats:  Logical-Router                :      1 *         72
21-Apr-2019 14:08:25 log: memstats:  Logical-Router Name           :      1 *         18
21-Apr-2019 14:08:25 log: memstats:  Priority queue                :      1 *         32
21-Apr-2019 14:08:25 log: memstats:  Priority queue data           :      1 *        256
21-Apr-2019 14:08:25 log: memstats:  Privilege information         :      2 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Thread                        :     13 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Thread master                 :      3 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Thread stats                  :      9 *         64
21-Apr-2019 14:08:25 log: memstats:  Vector                        :   7841 *         16
21-Apr-2019 14:08:25 log: memstats:  Vector index                  :   7841 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Work queue                    :      2 * (variably sized)
21-Apr-2019 14:08:25 log: memstats:  Work queue item               :      6 *         24
21-Apr-2019 14:08:25 log: memstats:  Work queue name string        :      1 * (variably sized)
21-Apr-2019 14:08:25 log: showing active allocations in memory group Label Manager
21-Apr-2019 14:08:25 log: showing active allocations in memory group zebra
21-Apr-2019 14:08:25 log: memstats:  MPLS LSP object               :      6 *         40
21-Apr-2019 14:08:25 log: memstats:  MPLS nexthop object           :      6 *         56
21-Apr-2019 14:08:25 log: memstats:  Zebra Name Space              :      1 *        264
21-Apr-2019 14:08:25
21-Apr-2019 14:08:25 2019-04-21 23:08:25,917 INFO: r1: stopping ospfd
21-Apr-2019 14:08:25 2019-04-21 23:08:25,921 INFO: r1: stopping zebra
21-Apr-2019 14:08:25 2019-04-21 23:08:25,921 INFO: r1: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:08:28
21-Apr-2019 14:08:28 r1: zebra crashed. Core file found - Backtrace follows:
21-Apr-2019 14:08:28 [New LWP 32672]
21-Apr-2019 14:08:28 [Thread debugging using libthread_db enabled]
21-Apr-2019 14:08:28 Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
21-Apr-2019 14:08:28 Core was generated by `/usr/lib/frr/zebra'.
21-Apr-2019 14:08:28 Program terminated with signal SIGABRT, Aborted.
21-Apr-2019 14:08:28 #0  0x00007f66ed3c7428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:08:28 #0  0x00007f66ed3c7428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:08:28 #1  0x00007f66ed3c902a in __GI_abort () at abort.c:89
21-Apr-2019 14:08:28 #2  0x00007f66eddc6354 in _zlog_assert_failed (assertion=assertion@entry=0x55fef5c6e782 "zvrf", file=file@entry=0x55fef5c6e76f "zebra/zebra_mpls.c", line=line@entry=961, function=function@entry=0x55fef5c6f060 <__func__.15728> "lsp_processq_del") at lib/log.c:710
21-Apr-2019 14:08:28 #3  0x000055fef5c38d6a in lsp_processq_del (wq=<optimized out>, data=0x55fef7a338c0) at zebra/zebra_mpls.c:961
21-Apr-2019 14:08:28 #4  0x00007f66eddebeee in work_queue_item_remove (wq=0x55fef7a1fc60, item=0x55fef7bd3530) at lib/workqueue.c:67
21-Apr-2019 14:08:28 #5  0x00007f66eddec375 in work_queue_free (wq=0x55fef7a1fc60) at lib/workqueue.c:112
21-Apr-2019 14:08:28 #6  0x000055fef5c2e0b7 in sigint () at zebra/main.c:152
21-Apr-2019 14:08:28 #7  0x00007f66eddd93e8 in quagga_sigevent_process () at lib/sigevent.c:103
21-Apr-2019 14:08:28 #8  0x00007f66edde564d in thread_fetch (m=m@entry=0x55fef786a5d0, fetch=fetch@entry=0x7ffd96ac2ff0) at lib/thread.c:1333
21-Apr-2019 14:08:28 #9  0x00007f66eddc39a3 in frr_run (master=0x55fef786a5d0) at lib/libfrr.c:878
21-Apr-2019 14:08:28 #10 0x000055fef5c21b5d in main (argc=1, argv=0x7ffd96ac32d8) at zebra/main.c:366
21-Apr-2019 14:08:28 2019-04-21 23:08:28,364 INFO:
21-Apr-2019 14:08:28 Router r1 zebra StdErr Log:
21-Apr-2019 14:08:28 log: showing active allocations in memory group libfrr
21-Apr-2019 14:08:28 log: memstats:  Host config                   :      3 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Command Tokens                :   3314 *         72
21-Apr-2019 14:08:28 log: memstats:  Command Token Text            :   2464 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Command Token Help            :   2464 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Command Argument Name         :    613 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Graph                         :     24 *          8
21-Apr-2019 14:08:28 log: memstats:  Graph Node                    :   3895 *         32
21-Apr-2019 14:08:28 log: memstats:  Hash                          :     52 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Hash Bucket                   :    590 *         32
21-Apr-2019 14:08:28 log: memstats:  Hash Index                    :     26 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Hook entry                    :      4 *         48
21-Apr-2019 14:08:28 log: memstats:  Link List                     :     10 *         40
21-Apr-2019 14:08:28 log: memstats:  Link Node                     :     36 *         24
21-Apr-2019 14:08:28 log: memstats:  Logging                       :      2 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Temporary memory              :      1 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Nexthop                       :      5 *        112
21-Apr-2019 14:08:28 log: memstats:  Nexthop label                 :      5 *          8
21-Apr-2019 14:08:28 log: memstats:  Logical-Router                :      1 *         72
21-Apr-2019 14:08:28 log: memstats:  Logical-Router Name           :      1 *         18
21-Apr-2019 14:08:28 log: memstats:  Priority queue                :      1 *         32
21-Apr-2019 14:08:28 log: memstats:  Priority queue data           :      1 *        256
21-Apr-2019 14:08:28 log: memstats:  Privilege information         :      2 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Thread                        :     13 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Thread master                 :      3 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Thread stats                  :      9 *         64
21-Apr-2019 14:08:28 log: memstats:  Vector                        :   7841 *         16
21-Apr-2019 14:08:28 log: memstats:  Vector index                  :   7841 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Work queue                    :      2 * (variably sized)
21-Apr-2019 14:08:28 log: memstats:  Work queue item               :      5 *         24
21-Apr-2019 14:08:28 log: memstats:  Work queue name string        :      1 * (variably sized)
21-Apr-2019 14:08:28 log: showing active allocations in memory group Label Manager
21-Apr-2019 14:08:28 log: showing active allocations in memory group zebra
21-Apr-2019 14:08:28 log: memstats:  MPLS LSP object               :      5 *         40
21-Apr-2019 14:08:28 log: memstats:  MPLS nexthop object           :      5 *         56
21-Apr-2019 14:08:28 log: memstats:  Zebra Name Space              :      1 *        264
21-Apr-2019 14:08:28
21-Apr-2019 14:08:28 2019-04-21 23:08:28,367 INFO: r2: stopping ospfd
21-Apr-2019 14:08:28 2019-04-21 23:08:28,372 INFO: r2: stopping zebra
21-Apr-2019 14:08:28 2019-04-21 23:08:28,372 INFO: r2: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:08:30
21-Apr-2019 14:08:30 r2: zebra crashed. Core file found - Backtrace follows:
21-Apr-2019 14:08:30 [New LWP 32704]
21-Apr-2019 14:08:30 [Thread debugging using libthread_db enabled]
21-Apr-2019 14:08:30 Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
21-Apr-2019 14:08:30 Core was generated by `/usr/lib/frr/zebra'.
21-Apr-2019 14:08:30 Program terminated with signal SIGABRT, Aborted.
21-Apr-2019 14:08:30 #0  0x00007f43e6c2b428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:08:30 #0  0x00007f43e6c2b428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:08:30 #1  0x00007f43e6c2d02a in __GI_abort () at abort.c:89
21-Apr-2019 14:08:30 #2  0x00007f43e762a354 in _zlog_assert_failed (assertion=assertion@entry=0x560baca7a782 "zvrf", file=file@entry=0x560baca7a76f "zebra/zebra_mpls.c", line=line@entry=961, function=function@entry=0x560baca7b060 <__func__.15728> "lsp_processq_del") at lib/log.c:710
21-Apr-2019 14:08:30 #3  0x0000560baca44d6a in lsp_processq_del (wq=<optimized out>, data=0x560bae20f8f0) at zebra/zebra_mpls.c:961
21-Apr-2019 14:08:30 #4  0x00007f43e764feee in work_queue_item_remove (wq=0x560bae05d7b0, item=0x560bae20fcf0) at lib/workqueue.c:67
21-Apr-2019 14:08:30 #5  0x00007f43e7650375 in work_queue_free (wq=0x560bae05d7b0) at lib/workqueue.c:112
21-Apr-2019 14:08:30 #6  0x0000560baca3a0b7 in sigint () at zebra/main.c:152
21-Apr-2019 14:08:30 #7  0x00007f43e763d3e8 in quagga_sigevent_process () at lib/sigevent.c:103
21-Apr-2019 14:08:30 #8  0x00007f43e764964d in thread_fetch (m=m@entry=0x560badea65d0, fetch=fetch@entry=0x7ffc62489a10) at lib/thread.c:1333
21-Apr-2019 14:08:30 #9  0x00007f43e76279a3 in frr_run (master=0x560badea65d0) at lib/libfrr.c:878
21-Apr-2019 14:08:30 #10 0x0000560baca2db5d in main (argc=1, argv=0x7ffc62489cf8) at zebra/main.c:366
21-Apr-2019 14:08:30 2019-04-21 23:08:30,774 INFO:
21-Apr-2019 14:08:30 Router r2 zebra StdErr Log:
21-Apr-2019 14:08:30 log: showing active allocations in memory group libfrr
21-Apr-2019 14:08:30 log: memstats:  Host config                   :      3 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Command Tokens                :   3314 *         72
21-Apr-2019 14:08:30 log: memstats:  Command Token Text            :   2464 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Command Token Help            :   2464 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Command Argument Name         :    613 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Graph                         :     24 *          8
21-Apr-2019 14:08:30 log: memstats:  Graph Node                    :   3895 *         32
21-Apr-2019 14:08:30 log: memstats:  Hash                          :     52 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Hash Bucket                   :    590 *         32
21-Apr-2019 14:08:30 log: memstats:  Hash Index                    :     26 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Hook entry                    :      4 *         48
21-Apr-2019 14:08:30 log: memstats:  Link List                     :     10 *         40
21-Apr-2019 14:08:30 log: memstats:  Link Node                     :     36 *         24
21-Apr-2019 14:08:30 log: memstats:  Logging                       :      2 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Temporary memory              :      1 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Nexthop                       :      7 *        112
21-Apr-2019 14:08:30 log: memstats:  Nexthop label                 :      7 *          8
21-Apr-2019 14:08:30 log: memstats:  Logical-Router                :      1 *         72
21-Apr-2019 14:08:30 log: memstats:  Logical-Router Name           :      1 *         18
21-Apr-2019 14:08:30 log: memstats:  Priority queue                :      1 *         32
21-Apr-2019 14:08:30 log: memstats:  Priority queue data           :      1 *        256
21-Apr-2019 14:08:30 log: memstats:  Privilege information         :      2 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Thread                        :     14 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Thread master                 :      3 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Thread stats                  :      9 *         64
21-Apr-2019 14:08:30 log: memstats:  Vector                        :   7841 *         16
21-Apr-2019 14:08:30 log: memstats:  Vector index                  :   7841 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Work queue                    :      2 * (variably sized)
21-Apr-2019 14:08:30 log: memstats:  Work queue item               :      7 *         24
21-Apr-2019 14:08:30 log: memstats:  Work queue name string        :      1 * (variably sized)
21-Apr-2019 14:08:30 log: showing active allocations in memory group Label Manager
21-Apr-2019 14:08:30 log: showing active allocations in memory group zebra
21-Apr-2019 14:08:30 log: memstats:  MPLS LSP object               :      7 *         40
21-Apr-2019 14:08:30 log: memstats:  MPLS nexthop object           :      7 *         56
21-Apr-2019 14:08:30 log: memstats:  Zebra Name Space              :      1 *        264
21-Apr-2019 14:08:30
21-Apr-2019 14:08:30 2019-04-21 23:08:30,778 INFO: r3: stopping ospfd
21-Apr-2019 14:08:30 2019-04-21 23:08:30,782 INFO: r3: stopping zebra
21-Apr-2019 14:08:30 2019-04-21 23:08:30,782 INFO: r3: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:08:33
21-Apr-2019 14:08:33 r3: zebra crashed. Core file found - Backtrace follows:
21-Apr-2019 14:08:33 [New LWP 32744]
21-Apr-2019 14:08:33 [Thread debugging using libthread_db enabled]
21-Apr-2019 14:08:33 Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
21-Apr-2019 14:08:33 Core was generated by `/usr/lib/frr/zebra'.
21-Apr-2019 14:08:33 Program terminated with signal SIGABRT, Aborted.
21-Apr-2019 14:08:33 #0  0x00007f7bb1058428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:08:33 #0  0x00007f7bb1058428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
21-Apr-2019 14:08:33 #1  0x00007f7bb105a02a in __GI_abort () at abort.c:89
21-Apr-2019 14:08:33 #2  0x00007f7bb1a57354 in _zlog_assert_failed (assertion=assertion@entry=0x55d428227782 "zvrf", file=file@entry=0x55d42822776f "zebra/zebra_mpls.c", line=line@entry=961, function=function@entry=0x55d428228060 <__func__.15728> "lsp_processq_del") at lib/log.c:710
21-Apr-2019 14:08:33 #3  0x000055d4281f1d6a in lsp_processq_del (wq=<optimized out>, data=0x55d42989d690) at zebra/zebra_mpls.c:961
21-Apr-2019 14:08:33 #4  0x00007f7bb1a7ceee in work_queue_item_remove (wq=0x55d4296e9c60, item=0x55d42989d4b0) at lib/workqueue.c:67
21-Apr-2019 14:08:33 #5  0x00007f7bb1a7d375 in work_queue_free (wq=0x55d4296e9c60) at lib/workqueue.c:112
21-Apr-2019 14:08:33 #6  0x000055d4281e70b7 in sigint () at zebra/main.c:152
21-Apr-2019 14:08:33 #7  0x00007f7bb1a6a3e8 in quagga_sigevent_process () at lib/sigevent.c:103
21-Apr-2019 14:08:33 #8  0x00007f7bb1a7664d in thread_fetch (m=m@entry=0x55d4295345d0, fetch=fetch@entry=0x7ffd0fe41720) at lib/thread.c:1333
21-Apr-2019 14:08:33 #9  0x00007f7bb1a549a3 in frr_run (master=0x55d4295345d0) at lib/libfrr.c:878
21-Apr-2019 14:08:33 #10 0x000055d4281dab5d in main (argc=1, argv=0x7ffd0fe41a08) at zebra/main.c:366
21-Apr-2019 14:08:33 2019-04-21 23:08:33,213 INFO:
21-Apr-2019 14:08:33 Router r3 zebra StdErr Log:
21-Apr-2019 14:08:33 log: showing active allocations in memory group libfrr
21-Apr-2019 14:08:33 log: memstats:  Host config                   :      3 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Command Tokens                :   3314 *         72
21-Apr-2019 14:08:33 log: memstats:  Command Token Text            :   2464 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Command Token Help            :   2464 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Command Argument Name         :    613 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Graph                         :     24 *          8
21-Apr-2019 14:08:33 log: memstats:  Graph Node                    :   3895 *         32
21-Apr-2019 14:08:33 log: memstats:  Hash                          :     52 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Hash Bucket                   :    590 *         32
21-Apr-2019 14:08:33 log: memstats:  Hash Index                    :     26 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Hook entry                    :      4 *         48
21-Apr-2019 14:08:33 log: memstats:  Link List                     :     10 *         40
21-Apr-2019 14:08:33 log: memstats:  Link Node                     :     36 *         24
21-Apr-2019 14:08:33 log: memstats:  Logging                       :      2 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Temporary memory              :      1 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Nexthop                       :      2 *        112
21-Apr-2019 14:08:33 log: memstats:  Nexthop label                 :      2 *          8
21-Apr-2019 14:08:33 log: memstats:  Logical-Router                :      1 *         72
21-Apr-2019 14:08:33 log: memstats:  Logical-Router Name           :      1 *         18
21-Apr-2019 14:08:33 log: memstats:  Priority queue                :      1 *         32
21-Apr-2019 14:08:33 log: memstats:  Priority queue data           :      1 *        256
21-Apr-2019 14:08:33 log: memstats:  Privilege information         :      2 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Thread                        :     12 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Thread master                 :      3 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Thread stats                  :      9 *         64
21-Apr-2019 14:08:33 log: memstats:  Vector                        :   7841 *         16
21-Apr-2019 14:08:33 log: memstats:  Vector index                  :   7841 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Work queue                    :      2 * (variably sized)
21-Apr-2019 14:08:33 log: memstats:  Work queue item               :      2 *         24
21-Apr-2019 14:08:33 log: memstats:  Work queue name string        :      1 * (variably sized)
21-Apr-2019 14:08:33 log: showing active allocations in memory group Label Manager
21-Apr-2019 14:08:33 log: showing active allocations in memory group zebra
21-Apr-2019 14:08:33 log: memstats:  MPLS LSP object               :      2 *         40
21-Apr-2019 14:08:33 log: memstats:  MPLS nexthop object           :      2 *         56
21-Apr-2019 14:08:33 log: memstats:  Zebra Name Space              :      1 *        264
21-Apr-2019 14:08:33
21-Apr-2019 14:08:33 PASSED2019-04-21 23:08:33,216 INFO: stopping topology: test_ospf_sr_topo1
21-Apr-2019 14:08:33 2019-04-21 23:08:33,224 INFO: stopping "s3"
21-Apr-2019 14:08:33 2019-04-21 23:08:33,224 INFO: stopping "s2"
21-Apr-2019 14:08:33 2019-04-21 23:08:33,224 INFO: stopping "s1"
21-Apr-2019 14:08:33 2019-04-21 23:08:33,232 INFO: stopping "s3"
21-Apr-2019 14:08:33 2019-04-21 23:08:33,232 INFO: stopping "s2"
21-Apr-2019 14:08:33 2019-04-21 23:08:33,232 INFO: stopping "s1"
21-Apr-2019 14:08:33 2019-04-21 23:08:33,803 INFO:
21-Apr-2019 14:08:33
21-Apr-2019 14:08:33 ---- OSPF Segment Routing tests End ----
21-Apr-2019 14:08:33
21-Apr-2019 14:08:33
21-Apr-2019 14:08:36 ospf-topo1/test_ospf_topo1.py::test_ospf_convergence 2019-04-21 23:08:36,032 INFO: loading topology: test_ospf_topo1
21-Apr-2019 14:08:36 2019-04-21 23:08:36,032 INFO: starting topology: test_ospf_topo1
21-Apr-2019 14:08:36 2019-04-21 23:08:36,098 INFO: r1: running version: 4.0
21-Apr-2019 14:08:36 2019-04-21 23:08:36,176 INFO: r4: running version: 4.0
21-Apr-2019 14:08:36 2019-04-21 23:08:36,177 INFO: r4: waiting for zebra to start (1 seconds)
21-Apr-2019 14:08:37 2019-04-21 23:08:37,541 INFO: r1: waiting for zebra to start (1 seconds)
21-Apr-2019 14:08:38 2019-04-21 23:08:38,886 INFO: r2: running version: 4.0
21-Apr-2019 14:08:38 2019-04-21 23:08:38,887 INFO: r2: waiting for zebra to start (1 seconds)
21-Apr-2019 14:08:40 2019-04-21 23:08:40,209 INFO: r3: running version: 4.0
21-Apr-2019 14:08:40 2019-04-21 23:08:40,210 INFO: r3: waiting for zebra to start (1 seconds)
21-Apr-2019 14:08:41 2019-04-21 23:08:41,931 INFO: Waiting for router "r4" convergence
21-Apr-2019 14:08:41 2019-04-21 23:08:41,932 INFO: 'router_output_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:09:32 2019-04-21 23:09:32,454 INFO: 'router_output_cmp' succeeded after 50.52 seconds
21-Apr-2019 14:09:32 2019-04-21 23:09:32,454 INFO: Waiting for router "r1" convergence
21-Apr-2019 14:09:32 2019-04-21 23:09:32,454 INFO: 'router_output_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:09:32 2019-04-21 23:09:32,532 INFO: 'router_output_cmp' succeeded after 0.08 seconds
21-Apr-2019 14:09:32 2019-04-21 23:09:32,532 INFO: Waiting for router "r2" convergence
21-Apr-2019 14:09:32 2019-04-21 23:09:32,532 INFO: 'router_output_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:09:32 2019-04-21 23:09:32,608 INFO: 'router_output_cmp' succeeded after 0.08 seconds
21-Apr-2019 14:09:32 2019-04-21 23:09:32,608 INFO: Waiting for router "r3" convergence
21-Apr-2019 14:09:32 2019-04-21 23:09:32,608 INFO: 'router_output_cmp' polling started (interval 0.5 secs, maximum wait 80 secs)
21-Apr-2019 14:09:32 2019-04-21 23:09:32,692 INFO: 'router_output_cmp' succeeded after 0.08 seconds
21-Apr-2019 14:09:32 PASSED
21-Apr-2019 14:09:33 ospf-topo1/test_ospf_topo1.py::test_ospf_kernel_route 2019-04-21 23:09:33,049 INFO: Checking OSPF IPv4 kernel routes in "r4"
21-Apr-2019 14:09:33 2019-04-21 23:09:33,051 INFO: Checking OSPF IPv4 kernel routes in "r1"
21-Apr-2019 14:09:33 2019-04-21 23:09:33,053 INFO: Checking OSPF IPv4 kernel routes in "r2"
21-Apr-2019 14:09:33 2019-04-21 23:09:33,055 INFO: Checking OSPF IPv4 kernel routes in "r3"
21-Apr-2019 14:09:33 PASSED
21-Apr-2019 14:09:33 ospf-topo1/test_ospf_topo1.py::test_ospf6_convergence 2019-04-21 23:09:33,413 INFO: Waiting for router "r1" IPv6 OSPF convergence
21-Apr-2019 14:09:33 2019-04-21 23:09:33,413 INFO: 'compare_show_ipv6_ospf6' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:09:33 2019-04-21 23:09:33,489 INFO: 'compare_show_ipv6_ospf6' succeeded after 0.08 seconds
21-Apr-2019 14:09:33 2019-04-21 23:09:33,489 INFO: Waiting for router "r2" IPv6 OSPF convergence
21-Apr-2019 14:09:33 2019-04-21 23:09:33,489 INFO: 'compare_show_ipv6_ospf6' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:09:33 2019-04-21 23:09:33,568 INFO: 'compare_show_ipv6_ospf6' succeeded after 0.08 seconds
21-Apr-2019 14:09:33 2019-04-21 23:09:33,568 INFO: Waiting for router "r3" IPv6 OSPF convergence
21-Apr-2019 14:09:33 2019-04-21 23:09:33,568 INFO: 'compare_show_ipv6_ospf6' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:09:33 2019-04-21 23:09:33,641 INFO: 'compare_show_ipv6_ospf6' succeeded after 0.07 seconds
21-Apr-2019 14:09:33 2019-04-21 23:09:33,641 INFO: Waiting for router "r4" IPv6 OSPF convergence
21-Apr-2019 14:09:33 2019-04-21 23:09:33,641 INFO: 'compare_show_ipv6_ospf6' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:09:33 2019-04-21 23:09:33,714 INFO: 'compare_show_ipv6_ospf6' succeeded after 0.07 seconds
21-Apr-2019 14:09:33 PASSED
21-Apr-2019 14:09:34 ospf-topo1/test_ospf_topo1.py::test_ospf6_kernel_route 2019-04-21 23:09:34,031 INFO: Checking OSPF IPv6 kernel routes in "r4"
21-Apr-2019 14:09:34 2019-04-21 23:09:34,033 INFO: Checking OSPF IPv6 kernel routes in "r1"
21-Apr-2019 14:09:34 2019-04-21 23:09:34,035 INFO: Checking OSPF IPv6 kernel routes in "r2"
21-Apr-2019 14:09:34 2019-04-21 23:09:34,037 INFO: Checking OSPF IPv6 kernel routes in "r3"
21-Apr-2019 14:09:34 PASSED
21-Apr-2019 14:09:34 ospf-topo1/test_ospf_topo1.py::test_ospf_json 2019-04-21 23:09:34,342 INFO: Comparing router "r1" "show ip ospf json" output
21-Apr-2019 14:09:34 2019-04-21 23:09:34,417 INFO: Comparing router "r2" "show ip ospf json" output
21-Apr-2019 14:09:34 2019-04-21 23:09:34,490 INFO: Comparing router "r3" "show ip ospf json" output
21-Apr-2019 14:09:34 2019-04-21 23:09:34,564 INFO: Comparing router "r4" "show ip ospf json" output
21-Apr-2019 14:09:34 PASSED
21-Apr-2019 14:09:34 ospf-topo1/test_ospf_topo1.py::test_ospf_link_down 2019-04-21 23:09:34,970 INFO: setting node "s3" link "s3-eth2" to state "down"
21-Apr-2019 14:09:34 2019-04-21 23:09:34,976 INFO: Waiting for router "r4" convergence after link failure
21-Apr-2019 14:09:34 2019-04-21 23:09:34,976 INFO: 'router_output_cmp' polling started (interval 0.5 secs, maximum wait 70 secs)
21-Apr-2019 14:09:35 2019-04-21 23:09:35,050 INFO: 'router_output_cmp' succeeded after 0.07 seconds
21-Apr-2019 14:09:35 2019-04-21 23:09:35,050 INFO: Waiting for router "r1" convergence after link failure
21-Apr-2019 14:09:35 2019-04-21 23:09:35,050 INFO: 'router_output_cmp' polling started (interval 0.5 secs, maximum wait 70 secs)
21-Apr-2019 14:10:12 2019-04-21 23:10:12,704 INFO: 'router_output_cmp' succeeded after 37.65 seconds
21-Apr-2019 14:10:12 2019-04-21 23:10:12,704 INFO: Waiting for router "r2" convergence after link failure
21-Apr-2019 14:10:12 2019-04-21 23:10:12,705 INFO: 'router_output_cmp' polling started (interval 0.5 secs, maximum wait 70 secs)
21-Apr-2019 14:10:12 2019-04-21 23:10:12,798 INFO: 'router_output_cmp' succeeded after 0.09 seconds
21-Apr-2019 14:10:12 2019-04-21 23:10:12,799 INFO: Waiting for router "r3" convergence after link failure
21-Apr-2019 14:10:12 2019-04-21 23:10:12,799 INFO: 'router_output_cmp' polling started (interval 0.5 secs, maximum wait 70 secs)
21-Apr-2019 14:10:12 2019-04-21 23:10:12,906 INFO: 'router_output_cmp' succeeded after 0.11 seconds
21-Apr-2019 14:10:12 PASSED
21-Apr-2019 14:10:13 ospf-topo1/test_ospf_topo1.py::test_ospf_link_down_kernel_route 2019-04-21 23:10:13,248 INFO: Checking OSPF IPv4 kernel routes in "r4" after link down
21-Apr-2019 14:10:13 2019-04-21 23:10:13,251 INFO: Checking OSPF IPv4 kernel routes in "r1" after link down
21-Apr-2019 14:10:13 2019-04-21 23:10:13,254 INFO: Checking OSPF IPv4 kernel routes in "r2" after link down
21-Apr-2019 14:10:13 2019-04-21 23:10:13,255 INFO: Checking OSPF IPv4 kernel routes in "r3" after link down
21-Apr-2019 14:10:13 PASSED
21-Apr-2019 14:10:13 ospf-topo1/test_ospf_topo1.py::test_ospf6_link_down 2019-04-21 23:10:13,590 INFO: Waiting for router "r1" IPv6 OSPF convergence after link down
21-Apr-2019 14:10:13 2019-04-21 23:10:13,591 INFO: 'compare_show_ipv6_ospf6' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:10:22 2019-04-21 23:10:22,990 INFO: 'compare_show_ipv6_ospf6' succeeded after 9.40 seconds
21-Apr-2019 14:10:22 2019-04-21 23:10:22,990 INFO: Waiting for router "r2" IPv6 OSPF convergence after link down
21-Apr-2019 14:10:22 2019-04-21 23:10:22,990 INFO: 'compare_show_ipv6_ospf6' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:10:23 2019-04-21 23:10:23,063 INFO: 'compare_show_ipv6_ospf6' succeeded after 0.07 seconds
21-Apr-2019 14:10:23 2019-04-21 23:10:23,063 INFO: Waiting for router "r3" IPv6 OSPF convergence after link down
21-Apr-2019 14:10:23 2019-04-21 23:10:23,064 INFO: 'compare_show_ipv6_ospf6' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:10:23 2019-04-21 23:10:23,136 INFO: 'compare_show_ipv6_ospf6' succeeded after 0.07 seconds
21-Apr-2019 14:10:23 2019-04-21 23:10:23,136 INFO: Waiting for router "r4" IPv6 OSPF convergence after link down
21-Apr-2019 14:10:23 2019-04-21 23:10:23,136 INFO: 'compare_show_ipv6_ospf6' polling started (interval 3 secs, maximum wait 75 secs)
21-Apr-2019 14:10:23 2019-04-21 23:10:23,212 INFO: 'compare_show_ipv6_ospf6' succeeded after 0.08 seconds
21-Apr-2019 14:10:23 PASSED
21-Apr-2019 14:10:23 ospf-topo1/test_ospf_topo1.py::test_ospf6_link_down_kernel_route 2019-04-21 23:10:23,654 INFO: Checking OSPF IPv6 kernel routes in "r4" after link down
21-Apr-2019 14:10:23 2019-04-21 23:10:23,658 INFO: Checking OSPF IPv6 kernel routes in "r1" after link down
21-Apr-2019 14:10:23 2019-04-21 23:10:23,661 INFO: Checking OSPF IPv6 kernel routes in "r2" after link down
21-Apr-2019 14:10:23 2019-04-21 23:10:23,663 INFO: Checking OSPF IPv6 kernel routes in "r3" after link down
21-Apr-2019 14:10:23 PASSED
21-Apr-2019 14:10:24 ospf-topo1/test_ospf_topo1.py::test_memory_leak 2019-04-21 23:10:24,307 INFO: r4: stopping ospf6d
21-Apr-2019 14:10:24 2019-04-21 23:10:24,315 INFO: r4: stopping ospfd
21-Apr-2019 14:10:24 2019-04-21 23:10:24,319 INFO: r4: stopping zebra
21-Apr-2019 14:10:24 2019-04-21 23:10:24,319 INFO: r4: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:10:26 2019-04-21 23:10:26,353 INFO: r1: stopping ospf6d
21-Apr-2019 14:10:26 2019-04-21 23:10:26,360 INFO: r1: stopping ospfd
21-Apr-2019 14:10:26 2019-04-21 23:10:26,363 INFO: r1: stopping zebra
21-Apr-2019 14:10:26 2019-04-21 23:10:26,363 INFO: r1: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:10:28 2019-04-21 23:10:28,399 INFO: r2: stopping ospf6d
21-Apr-2019 14:10:28 2019-04-21 23:10:28,402 INFO: r2: stopping ospfd
21-Apr-2019 14:10:28 2019-04-21 23:10:28,406 INFO: r2: stopping zebra
21-Apr-2019 14:10:28 2019-04-21 23:10:28,407 INFO: r2: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:10:30 2019-04-21 23:10:30,444 INFO: r3: stopping ospf6d
21-Apr-2019 14:10:30 2019-04-21 23:10:30,451 INFO: r3: stopping ospfd
21-Apr-2019 14:10:30 2019-04-21 23:10:30,456 INFO: r3: stopping zebra
21-Apr-2019 14:10:30 2019-04-21 23:10:30,459 INFO: r3: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:10:32 PASSED2019-04-21 23:10:32,486 INFO: stopping topology: test_ospf_topo1
21-Apr-2019 14:10:32 2019-04-21 23:10:32,494 INFO: stopping "s3"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,494 INFO: stopping "s2"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,494 INFO: stopping "s1"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,494 INFO: stopping "s6"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,494 INFO: stopping "s5"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,494 INFO: stopping "s4"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,502 INFO: stopping "s3"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,502 INFO: stopping "s2"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,502 INFO: stopping "s1"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,502 INFO: stopping "s6"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,502 INFO: stopping "s5"
21-Apr-2019 14:10:32 2019-04-21 23:10:32,502 INFO: stopping "s4"
21-Apr-2019 14:10:33
21-Apr-2019 14:10:35 ospf-topo1-vrf/test_ospf_topo1_vrf.py::test_ospf_convergence 2019-04-21 23:10:35,278 INFO: loading topology: test_ospf_topo1_vrf
21-Apr-2019 14:10:35 2019-04-21 23:10:35,278 INFO: starting topology: test_ospf_topo1_vrf
21-Apr-2019 14:10:35 2019-04-21 23:10:35,325 INFO: assert skipped at "test_ospf_topo1_vrf/test_ospf_convergence": Skipping OSPF VRF NETNS feature. VRF NETNS backend not available on FRR
21-Apr-2019 14:10:35 SKIPPED
21-Apr-2019 14:10:35 ospf-topo1-vrf/test_ospf_topo1_vrf.py::test_ospf_kernel_route 2019-04-21 23:10:35,329 INFO: assert skipped at "test_ospf_topo1_vrf/test_ospf_kernel_route": Skipping OSPF VRF NETNS feature. VRF NETNS backend not available on FRR
21-Apr-2019 14:10:35 SKIPPED
21-Apr-2019 14:10:35 ospf-topo1-vrf/test_ospf_topo1_vrf.py::test_ospf_json 2019-04-21 23:10:35,330 INFO: assert skipped at "test_ospf_topo1_vrf/test_ospf_json": Skipping OSPF VRF NETNS feature. VRF NETNS backend not available on FRR
21-Apr-2019 14:10:35 SKIPPED
21-Apr-2019 14:10:35 ospf-topo1-vrf/test_ospf_topo1_vrf.py::test_ospf_link_down 2019-04-21 23:10:35,337 INFO: assert skipped at "test_ospf_topo1_vrf/test_ospf_link_down": Skipping OSPF VRF NETNS feature. VRF NETNS backend not available on FRR
21-Apr-2019 14:10:35 SKIPPED
21-Apr-2019 14:10:35 ospf-topo1-vrf/test_ospf_topo1_vrf.py::test_ospf_link_down_kernel_route 2019-04-21 23:10:35,339 INFO: assert skipped at "test_ospf_topo1_vrf/test_ospf_link_down_kernel_route": Skipping OSPF VRF NETNS feature. VRF NETNS backend not available on FRR
21-Apr-2019 14:10:35 SKIPPED
21-Apr-2019 14:10:35 ospf-topo1-vrf/test_ospf_topo1_vrf.py::test_memory_leak 2019-04-21 23:10:35,342 INFO: assert skipped at "test_ospf_topo1_vrf/test_memory_leak": Skipping OSPF VRF NETNS feature. VRF NETNS backend not available on FRR
21-Apr-2019 14:10:35 SKIPPED
21-Apr-2019 14:10:37 ospf6-topo1/test_ospf6_topo1.py::test_router_running
21-Apr-2019 14:10:37
21-Apr-2019 14:10:37 ** test_ospf6_topo1: Setup Topology
21-Apr-2019 14:10:37 ******************************************
21-Apr-2019 14:10:37
21-Apr-2019 14:10:37 Cleanup old Mininet runs
21-Apr-2019 14:10:37 2019-04-21 23:10:37,242 INFO: r1: running version: 4.0
21-Apr-2019 14:10:37 2019-04-21 23:10:37,263 INFO: r1: waiting for zebra to start (1 seconds)
21-Apr-2019 14:10:38 2019-04-21 23:10:38,305 INFO: r2: running version: 4.0
21-Apr-2019 14:10:38 2019-04-21 23:10:38,306 INFO: r2: waiting for zebra to start (1 seconds)
21-Apr-2019 14:10:39 2019-04-21 23:10:39,353 INFO: r3: running version: 4.0
21-Apr-2019 14:10:39 2019-04-21 23:10:39,354 INFO: r3: waiting for zebra to start (1 seconds)
21-Apr-2019 14:10:40 2019-04-21 23:10:40,404 INFO: r4: running version: 4.0
21-Apr-2019 14:10:40 2019-04-21 23:10:40,405 INFO: r4: waiting for zebra to start (1 seconds)
21-Apr-2019 14:10:46
21-Apr-2019 14:10:46
21-Apr-2019 14:10:46 ** Check if FRR/Quagga is running on each Router node
21-Apr-2019 14:10:46 ******************************************
21-Apr-2019 14:10:46
21-Apr-2019 14:10:46 PASSED
21-Apr-2019 14:10:46 ospf6-topo1/test_ospf6_topo1.py::test_ospf6_converged
21-Apr-2019 14:10:46
21-Apr-2019 14:10:46 ** Verify OSPF6 daemons to converge
21-Apr-2019 14:10:46 ******************************************
21-Apr-2019 14:10:46
21-Apr-2019 14:10:46 Timeout in 60:  Waiting for r1
21-Apr-2019 14:10:51 Timeout in 55:  Waiting for r1
21-Apr-2019 14:10:57 Timeout in 50:  Waiting for r1
21-Apr-2019 14:11:02 Timeout in 45:  Waiting for r1
21-Apr-2019 14:11:07 Timeout in 40:  Waiting for r1
21-Apr-2019 14:11:12 Timeout in 35:  Waiting for r1
21-Apr-2019 14:11:17 Timeout in 30:  Waiting for r1
21-Apr-2019 14:11:38 Timeout in 25:  Done
21-Apr-2019 14:11:38
21-Apr-2019 14:11:38 OSPFv3 converged.
21-Apr-2019 14:11:38
21-Apr-2019 14:11:38 waiting 15s for routes to populate
21-Apr-2019 14:11:38 PASSED
21-Apr-2019 14:11:38 ospf6-topo1/test_ospf6_topo1.py::test_ospfv3_routingTable
21-Apr-2019 14:11:38
21-Apr-2019 14:11:38 ** Verifying OSPFv3 Routing Table
21-Apr-2019 14:11:38 ******************************************
21-Apr-2019 14:11:38
21-Apr-2019 14:11:38 r1 ok
21-Apr-2019 14:11:38 r2 ok
21-Apr-2019 14:11:38 r3 ok
21-Apr-2019 14:11:38 r4 ok
21-Apr-2019 14:11:38 PASSED
21-Apr-2019 14:11:38 ospf6-topo1/test_ospf6_topo1.py::test_linux_ipv6_kernel_routingTable
21-Apr-2019 14:11:38
21-Apr-2019 14:11:38 ** Verifying Linux IPv6 Kernel Routing Table
21-Apr-2019 14:11:38 ******************************************
21-Apr-2019 14:11:38
21-Apr-2019 14:11:38 r1 ok
21-Apr-2019 14:11:38 r2 ok
21-Apr-2019 14:11:38 r3 ok
21-Apr-2019 14:11:38 r4 ok
21-Apr-2019 14:11:38 PASSED
21-Apr-2019 14:11:38 ospf6-topo1/test_ospf6_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:11:38
21-Apr-2019 14:11:38 ** Verifying unexpected STDERR output from daemons
21-Apr-2019 14:11:38 ******************************************
21-Apr-2019 14:11:38
21-Apr-2019 14:11:38 2019-04-21 23:11:38,851 INFO: r1: stopping ospf6d
21-Apr-2019 14:11:38 2019-04-21 23:11:38,857 INFO: r1: stopping zebra
21-Apr-2019 14:11:38 2019-04-21 23:11:38,857 INFO: r1: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:11:40 2019-04-21 23:11:40,887 INFO: r2: stopping ospf6d
21-Apr-2019 14:11:40 2019-04-21 23:11:40,898 INFO: r2: stopping zebra
21-Apr-2019 14:11:40 2019-04-21 23:11:40,898 INFO: r2: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:11:42 2019-04-21 23:11:42,926 INFO: r3: stopping ospf6d
21-Apr-2019 14:11:42 2019-04-21 23:11:42,934 INFO: r3: stopping zebra
21-Apr-2019 14:11:42 2019-04-21 23:11:42,935 INFO: r3: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:11:44 2019-04-21 23:11:44,960 INFO: r4: stopping ospf6d
21-Apr-2019 14:11:44 2019-04-21 23:11:44,965 INFO: r4: stopping zebra
21-Apr-2019 14:11:44 2019-04-21 23:11:44,967 INFO: r4: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:11:46 PASSED
21-Apr-2019 14:11:47 ospf6-topo1/test_ospf6_topo1.py::test_shutdown_check_memleak PASSED
21-Apr-2019 14:11:47
21-Apr-2019 14:11:47 ** test_ospf6_topo1: Shutdown Topology
21-Apr-2019 14:11:47 ******************************************
21-Apr-2019 14:11:47
21-Apr-2019 14:11:47
21-Apr-2019 14:11:49 rip-topo1/test_rip_topo1.py::test_router_running
21-Apr-2019 14:11:49
21-Apr-2019 14:11:49 ** test_rip_topo1: Setup Topology
21-Apr-2019 14:11:49 ******************************************
21-Apr-2019 14:11:49
21-Apr-2019 14:11:49 Cleanup old Mininet runs
21-Apr-2019 14:11:49 2019-04-21 23:11:49,641 INFO: r1: running version: 4.0
21-Apr-2019 14:11:49 2019-04-21 23:11:49,642 INFO: r1: waiting for zebra to start (1 seconds)
21-Apr-2019 14:11:50 2019-04-21 23:11:50,674 INFO: r2: running version: 4.0
21-Apr-2019 14:11:50 2019-04-21 23:11:50,676 INFO: r2: waiting for zebra to start (1 seconds)
21-Apr-2019 14:11:51 2019-04-21 23:11:51,713 INFO: r3: running version: 4.0
21-Apr-2019 14:11:51 2019-04-21 23:11:51,714 INFO: r3: waiting for zebra to start (1 seconds)
21-Apr-2019 14:11:58
21-Apr-2019 14:11:58
21-Apr-2019 14:11:58 ** Check if FRR/Quagga is running on each Router node
21-Apr-2019 14:11:58 ******************************************
21-Apr-2019 14:11:58
21-Apr-2019 14:11:58 PASSED
21-Apr-2019 14:12:58 rip-topo1/test_rip_topo1.py::test_converge_protocols
21-Apr-2019 14:12:58
21-Apr-2019 14:12:58 ** Waiting for protocols convergence
21-Apr-2019 14:12:58 ******************************************
21-Apr-2019 14:12:58
21-Apr-2019 14:12:58 PASSED
21-Apr-2019 14:12:58 rip-topo1/test_rip_topo1.py::test_rip_status
21-Apr-2019 14:12:58
21-Apr-2019 14:12:58 ** Verifing RIP status
21-Apr-2019 14:12:58 ******************************************
21-Apr-2019 14:12:58
21-Apr-2019 14:12:58 r1 ok
21-Apr-2019 14:12:58 r2 ok
21-Apr-2019 14:12:58 r3 ok
21-Apr-2019 14:12:58 PASSED
21-Apr-2019 14:12:59 rip-topo1/test_rip_topo1.py::test_rip_routes
21-Apr-2019 14:12:59
21-Apr-2019 14:12:59 ** Verifing RIP routes
21-Apr-2019 14:12:59 ******************************************
21-Apr-2019 14:12:59
21-Apr-2019 14:12:59 r1 ok
21-Apr-2019 14:12:59 r2 ok
21-Apr-2019 14:12:59 r3 ok
21-Apr-2019 14:12:59 PASSED
21-Apr-2019 14:12:59 rip-topo1/test_rip_topo1.py::test_zebra_ipv4_routingTable
21-Apr-2019 14:12:59
21-Apr-2019 14:12:59 ** Verifing Zebra IPv4 Routing Table
21-Apr-2019 14:12:59 ******************************************
21-Apr-2019 14:12:59
21-Apr-2019 14:12:59 r1 ok
21-Apr-2019 14:12:59 r2 ok
21-Apr-2019 14:12:59 r3 ok
21-Apr-2019 14:12:59 PASSED
21-Apr-2019 14:12:59 rip-topo1/test_rip_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:12:59
21-Apr-2019 14:12:59 ** Verifing unexpected STDERR output from daemons
21-Apr-2019 14:12:59 ******************************************
21-Apr-2019 14:12:59
21-Apr-2019 14:12:59 2019-04-21 23:12:59,702 INFO: r1: stopping ripd
21-Apr-2019 14:12:59 2019-04-21 23:12:59,705 INFO: r1: stopping zebra
21-Apr-2019 14:12:59 2019-04-21 23:12:59,707 INFO: r1: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:13:02 PASSED
21-Apr-2019 14:13:02
21-Apr-2019 14:13:02 ** test_rip_topo1: Shutdown Topology
21-Apr-2019 14:13:02 ******************************************
21-Apr-2019 14:13:02
21-Apr-2019 14:13:02 2019-04-21 23:13:02,029 INFO: r2: stopping ripd
21-Apr-2019 14:13:02 2019-04-21 23:13:02,032 INFO: r2: stopping zebra
21-Apr-2019 14:13:02 2019-04-21 23:13:02,035 INFO: r2: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:13:04 2019-04-21 23:13:04,150 INFO: r3: stopping ripd
21-Apr-2019 14:13:04 2019-04-21 23:13:04,154 INFO: r3: stopping zebra
21-Apr-2019 14:13:04 2019-04-21 23:13:04,156 INFO: r3: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:13:06
21-Apr-2019 14:13:08 ripng-topo1/test_ripng_topo1.py::test_router_running
21-Apr-2019 14:13:08
21-Apr-2019 14:13:08 ** test_ripng_topo1: Setup Topology
21-Apr-2019 14:13:08 ******************************************
21-Apr-2019 14:13:08
21-Apr-2019 14:13:08 Cleanup old Mininet runs
21-Apr-2019 14:13:08 2019-04-21 23:13:08,148 INFO: r1: running version: 4.0
21-Apr-2019 14:13:08 2019-04-21 23:13:08,149 INFO: r1: waiting for zebra to start (1 seconds)
21-Apr-2019 14:13:09 2019-04-21 23:13:09,194 INFO: r2: running version: 4.0
21-Apr-2019 14:13:09 2019-04-21 23:13:09,195 INFO: r2: waiting for zebra to start (1 seconds)
21-Apr-2019 14:13:10 2019-04-21 23:13:10,237 INFO: r3: running version: 4.0
21-Apr-2019 14:13:10 2019-04-21 23:13:10,238 INFO: r3: waiting for zebra to start (1 seconds)
21-Apr-2019 14:13:16
21-Apr-2019 14:13:16
21-Apr-2019 14:13:16 ** Check if FRR/Quagga is running on each Router node
21-Apr-2019 14:13:16 ******************************************
21-Apr-2019 14:13:16
21-Apr-2019 14:13:16 PASSED
21-Apr-2019 14:14:16 ripng-topo1/test_ripng_topo1.py::test_converge_protocols
21-Apr-2019 14:14:16
21-Apr-2019 14:14:16 ** Waiting for protocols convergence
21-Apr-2019 14:14:16 ******************************************
21-Apr-2019 14:14:16
21-Apr-2019 14:14:16 PASSED
21-Apr-2019 14:14:17 ripng-topo1/test_ripng_topo1.py::test_ripng_status
21-Apr-2019 14:14:17
21-Apr-2019 14:14:17 ** Verifying RIPng status
21-Apr-2019 14:14:17 ******************************************
21-Apr-2019 14:14:17
21-Apr-2019 14:14:17 r1 ok
21-Apr-2019 14:14:17 r2 ok
21-Apr-2019 14:14:17 r3 ok
21-Apr-2019 14:14:17 PASSED
21-Apr-2019 14:14:17 ripng-topo1/test_ripng_topo1.py::test_ripng_routes
21-Apr-2019 14:14:17
21-Apr-2019 14:14:17 ** Verifying RIPng routes
21-Apr-2019 14:14:17 ******************************************
21-Apr-2019 14:14:17
21-Apr-2019 14:14:17 r1 ok
21-Apr-2019 14:14:17 r2 ok
21-Apr-2019 14:14:17 r3 ok
21-Apr-2019 14:14:17 PASSED
21-Apr-2019 14:14:18 ripng-topo1/test_ripng_topo1.py::test_zebra_ipv6_routingTable
21-Apr-2019 14:14:18
21-Apr-2019 14:14:18 ** Verifying Zebra IPv6 Routing Table
21-Apr-2019 14:14:18 ******************************************
21-Apr-2019 14:14:18
21-Apr-2019 14:14:18 r1 ok
21-Apr-2019 14:14:18 r2 ok
21-Apr-2019 14:14:18 r3 ok
21-Apr-2019 14:14:18 PASSED
21-Apr-2019 14:14:18 ripng-topo1/test_ripng_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:14:18
21-Apr-2019 14:14:18 ** Verifying unexpected STDERR output from daemons
21-Apr-2019 14:14:18 ******************************************
21-Apr-2019 14:14:18
21-Apr-2019 14:14:18 2019-04-21 23:14:18,264 INFO: r1: stopping ripngd
21-Apr-2019 14:14:18 2019-04-21 23:14:18,269 INFO: r1: stopping zebra
21-Apr-2019 14:14:18 2019-04-21 23:14:18,269 INFO: r1: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:14:20 PASSED
21-Apr-2019 14:14:20 ripng-topo1/test_ripng_topo1.py::test_shutdown_check_memleak PASSED
21-Apr-2019 14:14:20
21-Apr-2019 14:14:20 ** test_ripng_topo1: Shutdown Topology
21-Apr-2019 14:14:20 ******************************************
21-Apr-2019 14:14:20
21-Apr-2019 14:14:20 2019-04-21 23:14:20,589 INFO: r2: stopping ripngd
21-Apr-2019 14:14:20 2019-04-21 23:14:20,592 INFO: r2: stopping zebra
21-Apr-2019 14:14:20 2019-04-21 23:14:20,595 INFO: r2: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:14:22 2019-04-21 23:14:22,722 INFO: r3: stopping ripngd
21-Apr-2019 14:14:22 2019-04-21 23:14:22,724 INFO: r3: stopping zebra
21-Apr-2019 14:14:22 2019-04-21 23:14:22,726 INFO: r3: waiting for daemons stopping (2 seconds)
21-Apr-2019 14:14:24
21-Apr-2019 14:14:24
21-Apr-2019 14:14:24 =============================== warnings summary ===============================
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_router_running
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_error_messages_vtysh
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_error_messages_daemons
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_converge_protocols
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_rip_status
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_ripng_status
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_ospfv2_interfaces
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_isis_interfaces
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_bgp_summary
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_bgp_ipv6_summary
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_bgp_ipv4
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_bgp_ipv6
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_mpls_interfaces
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_shutdown_check_stderr
21-Apr-2019 14:14:24 all-protocol-startup/test_all_protocol_startup.py::test_shutdown_check_memleak
21-Apr-2019 14:14:24 bfd-topo1/test_bfd_topo1.py::test_bfd_connection
21-Apr-2019 14:14:24 bfd-topo1/test_bfd_topo1.py::test_bgp_convergence
21-Apr-2019 14:14:24 bfd-topo1/test_bfd_topo1.py::test_bgp_fast_convergence
21-Apr-2019 14:14:24 bfd-topo1/test_bfd_topo1.py::test_bfd_fast_convergence
21-Apr-2019 14:14:24 bfd-topo1/test_bfd_topo1.py::test_bgp_fast_reconvergence
21-Apr-2019 14:14:24 bfd-topo1/test_bfd_topo1.py::test_memory_leak
21-Apr-2019 14:14:24 bgp-ecmp-topo1/test_bgp_ecmp_topo1.py::test_bgp_convergence
21-Apr-2019 14:14:24 bgp-ecmp-topo1/test_bgp_ecmp_topo1.py::test_bgp_ecmp
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_direct/test_bgp_l3vpn_to_bgp_direct.py::test_adjacencies
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_direct/test_bgp_l3vpn_to_bgp_direct.py::test_add_routes
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_direct/test_bgp_l3vpn_to_bgp_direct.py::test_check_routes
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_direct/test_bgp_l3vpn_to_bgp_direct.py::test_cleanup_all
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_direct/test_bgp_l3vpn_to_bgp_direct.py::test_memory_leak
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_vrf/test_bgp_l3vpn_to_bgp_vrf.py::test_check_linux_vrf
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_vrf/test_bgp_l3vpn_to_bgp_vrf.py::test_adjacencies
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_vrf/test_bgp_l3vpn_to_bgp_vrf.py::test_check_routes
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_vrf/test_bgp_l3vpn_to_bgp_vrf.py::test_check_linux_mpls
21-Apr-2019 14:14:24 bgp_l3vpn_to_bgp_vrf/test_bgp_l3vpn_to_bgp_vrf.py::test_memory_leak
21-Apr-2019 14:14:24 bgp_multiview_topo1/test_bgp_multiview_topo1.py::test_router_running
21-Apr-2019 14:14:24 bgp_multiview_topo1/test_bgp_multiview_topo1.py::test_bgp_converge
21-Apr-2019 14:14:24 bgp_multiview_topo1/test_bgp_multiview_topo1.py::test_bgp_routingTable
21-Apr-2019 14:14:24 bgp_multiview_topo1/test_bgp_multiview_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:14:24 bgp_multiview_topo1/test_bgp_multiview_topo1.py::test_shutdown_check_memleak
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity/test_bgp_rfapi_basic_sanity.py::test_add_routes
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity/test_bgp_rfapi_basic_sanity.py::test_adjacencies
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity/test_bgp_rfapi_basic_sanity.py::test_check_routes
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity/test_bgp_rfapi_basic_sanity.py::test_check_close
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity/test_bgp_rfapi_basic_sanity.py::test_check_timeout
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity/test_bgp_rfapi_basic_sanity.py::test_cleanup_all
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity/test_bgp_rfapi_basic_sanity.py::test_memory_leak
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity_config2/test_bgp_rfapi_basic_sanity_config2.py::test_add_routes
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity_config2/test_bgp_rfapi_basic_sanity_config2.py::test_adjacencies
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity_config2/test_bgp_rfapi_basic_sanity_config2.py::test_check_routes
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity_config2/test_bgp_rfapi_basic_sanity_config2.py::test_check_close
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity_config2/test_bgp_rfapi_basic_sanity_config2.py::test_check_timeout
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity_config2/test_bgp_rfapi_basic_sanity_config2.py::test_cleanup_all
21-Apr-2019 14:14:24 bgp_rfapi_basic_sanity_config2/test_bgp_rfapi_basic_sanity_config2.py::test_memory_leak
21-Apr-2019 14:14:24 eigrp-topo1/test_eigrp_topo1.py::test_converge_protocols
21-Apr-2019 14:14:24 eigrp-topo1/test_eigrp_topo1.py::test_eigrp_routes
21-Apr-2019 14:14:24 eigrp-topo1/test_eigrp_topo1.py::test_zebra_ipv4_routingTable
21-Apr-2019 14:14:24 eigrp-topo1/test_eigrp_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:14:24 isis-topo1/test_isis_topo1.py::test_isis_convergence
21-Apr-2019 14:14:24 isis-topo1/test_isis_topo1.py::test_isis_route_installation
21-Apr-2019 14:14:24 isis-topo1/test_isis_topo1.py::test_isis_linux_route_installation
21-Apr-2019 14:14:24 isis-topo1/test_isis_topo1.py::test_isis_route6_installation
21-Apr-2019 14:14:24 isis-topo1/test_isis_topo1.py::test_isis_linux_route6_installation
21-Apr-2019 14:14:24 isis-topo1/test_isis_topo1.py::test_memory_leak
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_router_running
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_mpls_interfaces
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_mpls_ldp_neighbor_establish
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_mpls_ldp_discovery
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_mpls_ldp_neighbor
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_mpls_ldp_binding
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_zebra_ipv4_routingTable
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_mpls_table
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_linux_mpls_routes
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:14:24 ldp-topo1/test_ldp_topo1.py::test_shutdown_check_memleak
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ospf_convergence
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_rib
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_adjacencies
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_neighbors
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_bindings
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_pwid_bindings
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_pseudowires
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_ldp_pseudowires_after_link_down
21-Apr-2019 14:14:24 ldp-vpls-topo1/test_ldp_vpls_topo1.py::test_memory_leak
21-Apr-2019 14:14:24 ospf-sr-topo1/test_ospf_sr_topo1.py::test_ospf_sr
21-Apr-2019 14:14:24 ospf-sr-topo1/test_ospf_sr_topo1.py::test_ospf_kernel_route
21-Apr-2019 14:14:24 ospf-sr-topo1/test_ospf_sr_topo1.py::test_memory_leak
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf_convergence
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf_kernel_route
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf6_convergence
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf6_kernel_route
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf_json
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf_link_down
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf_link_down_kernel_route
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf6_link_down
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_ospf6_link_down_kernel_route
21-Apr-2019 14:14:24 ospf-topo1/test_ospf_topo1.py::test_memory_leak
21-Apr-2019 14:14:24 ospf6-topo1/test_ospf6_topo1.py::test_router_running
21-Apr-2019 14:14:24 ospf6-topo1/test_ospf6_topo1.py::test_ospf6_converged
21-Apr-2019 14:14:24 ospf6-topo1/test_ospf6_topo1.py::test_ospfv3_routingTable
21-Apr-2019 14:14:24 ospf6-topo1/test_ospf6_topo1.py::test_linux_ipv6_kernel_routingTable
21-Apr-2019 14:14:24 ospf6-topo1/test_ospf6_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:14:24 ospf6-topo1/test_ospf6_topo1.py::test_shutdown_check_memleak
21-Apr-2019 14:14:24 rip-topo1/test_rip_topo1.py::test_router_running
21-Apr-2019 14:14:24 rip-topo1/test_rip_topo1.py::test_converge_protocols
21-Apr-2019 14:14:24 rip-topo1/test_rip_topo1.py::test_rip_status
21-Apr-2019 14:14:24 rip-topo1/test_rip_topo1.py::test_rip_routes
21-Apr-2019 14:14:24 rip-topo1/test_rip_topo1.py::test_zebra_ipv4_routingTable
21-Apr-2019 14:14:24 rip-topo1/test_rip_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:14:24 ripng-topo1/test_ripng_topo1.py::test_router_running
21-Apr-2019 14:14:24 ripng-topo1/test_ripng_topo1.py::test_converge_protocols
21-Apr-2019 14:14:24 ripng-topo1/test_ripng_topo1.py::test_ripng_status
21-Apr-2019 14:14:24 ripng-topo1/test_ripng_topo1.py::test_ripng_routes
21-Apr-2019 14:14:24 ripng-topo1/test_ripng_topo1.py::test_zebra_ipv6_routingTable
21-Apr-2019 14:14:24 ripng-topo1/test_ripng_topo1.py::test_shutdown_check_stderr
21-Apr-2019 14:14:24 ripng-topo1/test_ripng_topo1.py::test_shutdown_check_memleak
21-Apr-2019 14:14:24   /root/bamboo-agent-home/xml-data/build-dir/FRR-TOPOPR-T4B/topotests/conftest.py:25: PytestDeprecationWarning: the `pytest.config` global is deprecated.  Please use `request.config` or `pytest_configure` (if you're a pytest plugin) instead.
21-Apr-2019 14:14:24     if pytest.config.getoption('--topology-only'):
21-Apr-2019 14:14:24
21-Apr-2019 14:14:24 -- Docs: https://docs.pytest.org/en/latest/warnings.html
21-Apr-2019 14:14:24 - generated xml file: /root/bamboo-agent-home/xml-data/build-dir/FRR-TOPOPR-T4B/topotests.xml -
21-Apr-2019 14:14:24 ====== 1 failed, 103 passed, 20 skipped, 114 warnings in 1107.45 seconds =======
21-Apr-2019 14:14:24 Topotests exit status: tests failed
21-Apr-2019 14:14:24 Finished task 'Run Topology Tests' with result: Success
21-Apr-2019 14:14:25 Starting task 'Parse Topology Test Results' of type 'com.atlassian.bamboo.plugins.testresultparser:task.testresultparser.junit'
21-Apr-2019 14:14:25 Parsing test results under /root/bamboo-agent-home/xml-data/build-dir/FRR-TOPOPR-T4B...
21-Apr-2019 14:14:25 Failing task since 1 failing test cases were found.
21-Apr-2019 14:14:25 Finished task 'Parse Topology Test Results' with result: Failed
21-Apr-2019 14:14:25 Running post build plugin 'Docker Container Cleanup'
21-Apr-2019 14:14:25 Running post build plugin 'NCover Results Collector'
21-Apr-2019 14:14:25 Running post build plugin 'Clover Results Collector'
21-Apr-2019 14:14:25 Running post build plugin 'npm Cache Cleanup'
21-Apr-2019 14:14:25 Running post build plugin 'Artifact Copier'
21-Apr-2019 14:14:25 Publishing an artifact: ErrorLog
21-Apr-2019 14:14:26 Finished publishing of artifact Non required job artifact: [ErrorLog], pattern: [log_*.txt] anchored at: [topotests] in 824.0 ms
21-Apr-2019 14:14:26 Publishing an artifact: MemoryLeaks
21-Apr-2019 14:14:26 Finished publishing of artifact Non required job artifact: [MemoryLeaks], pattern: [memleak*.txt] anchored at: [topotests] in 169.6 ms
21-Apr-2019 14:14:26 Publishing an artifact: TestExecutionLogs
21-Apr-2019 14:14:27 Finished publishing of artifact Non required job artifact: [TestExecutionLogs], pattern: [**] anchored at: [/tmp/topotests] in 1.734 s
21-Apr-2019 14:14:28 Successfully removed working directory at '/root/bamboo-agent-home/xml-data/build-dir/FRR-TOPOPR-T4B'
21-Apr-2019 14:14:28 Finalising the build...
21-Apr-2019 14:14:28 Stopping timer.
21-Apr-2019 14:14:28 Build FRR-TOPOPR-T4B-395 completed.
21-Apr-2019 14:14:29 Running on server: post build plugin 'NCover Results Collector'
21-Apr-2019 14:14:29 Running on server: post build plugin 'Build Hanging Detection Configuration'
21-Apr-2019 14:14:29 Running on server: post build plugin 'Clover Delta Calculator'
21-Apr-2019 14:14:29 Running on server: post build plugin 'Maven Dependencies Postprocessor'
21-Apr-2019 14:14:29 All post build plugins have finished
21-Apr-2019 14:14:29 Generating build results summary...
21-Apr-2019 14:14:29 Saving build results to disk...
21-Apr-2019 14:14:29 Logging substituted variables...
21-Apr-2019 14:14:29 Indexing build results...
21-Apr-2019 14:14:29 Finished building FRR-TOPOPR-T4B-395.