namazu
namazu copied to clipboard
osrg
Flaky test: nmz/endpoint
4919228 https://travis-ci.org/osrg/namazu/builds/134960743
ok github.com/osrg/namazu/nmz/cli 2.768s coverage: 0.3% of statements
ok github.com/osrg/namazu/nmz/cli/container/run 2.432s coverage: 0.0% of statements
ok github.com/osrg/namazu/nmz/cli/inspectors 2.568s coverage: 12.6% of statements
ok github.com/osrg/namazu/nmz/cli/tools 1.024s coverage: 2.5% of statements
ok github.com/osrg/namazu/nmz/container 2.534s coverage: 0.0% of statements
ok github.com/osrg/namazu/nmz/container/ns 1.025s coverage: 0.0% of statements
No output has been received in the last 10m0s, this potentially indicates a stalled build or something wrong with the build itself.
The build has been terminated
Typical output: https://travis-ci.org/osrg/namazu/builds/134956146
ok github.com/osrg/namazu/nmz/cli 2.220s coverage: 0.3% of statements
ok github.com/osrg/namazu/nmz/cli/container/run 2.226s coverage: 0.0% of statements
ok github.com/osrg/namazu/nmz/cli/inspectors 2.230s coverage: 12.6% of statements
ok github.com/osrg/namazu/nmz/cli/tools 1.017s coverage: 2.5% of statements
ok github.com/osrg/namazu/nmz/container 2.223s coverage: 0.0% of statements
ok github.com/osrg/namazu/nmz/container/ns 1.015s coverage: 0.0% of statements
ok github.com/osrg/namazu/nmz/endpoint 2.404s coverage: 72.1% of statements <--- this
...
locally reproducible. TestEndpointWithPacketEvent_256_4 seems hanging.
49192284350646fd76cf8a4f48eac467758fd44f a.txt
| Test command | Reproducible? |
|---|---|
for f in $(seq 1 5000);do ./endpoint.test -test.run TestEndpointWithPacketEvent_1_1 -test.v ; done |
Yes :exclamation: |
for f in $(seq 1 5000);do ./endpoint.test -test.run TestEndpointWithPacketEvent_256_4 -test.v ; done |
Yes |
./endpoint.test -test.run TestEndpointWithPacketEvent_1_1 -test.v -test.count 5000 |
No |
./endpoint.test -test.run TestEndpointWithPacketEvent_256_4 -test.v -test.count 5000 |
No:exclamation: |
The result suggests that the cause of the issue is just related to the initialization of the test process. So the issue is not likely to happen in the usual case.
minimized log:
=== RUN TestEndpointWithPacketEvent_1_1
[NMZ-DBG] 09:59:17.61: REST getting action http://127.0.0.1:43185/api/v3/actions/restentity-2 (at log.go:210)
[NMZ-DBG] 09:59:17.61: REST getting action http://127.0.0.1:43185/api/v3/actions/restentity-3 (at log.go:210)
[NMZ-DBG] 09:59:17.61: ActionQueue[restentity-1]: Peeking (at log.go:210)
[NMZ-DBG] 09:59:17.61: LOCAL EP handling event Signal{map[string]interface {}{"class":"PacketEvent", "option":map[string]interface {}{"src_entity":"localentity-0", "dst_entit
y":"localentity-0", "value":0}, "type":"event", "deferred":true, "uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1", "entity":"localentity-0"}} (at log.go:210)
[NMZ-DBG] 09:59:17.61: LOCAL EP handled event Signal{map[string]interface {}{"entity":"localentity-0", "class":"PacketEvent", "option":map[string]interface {}{"src_entity":"l
ocalentity-0", "dst_entity":"localentity-0", "value":0}, "type":"event", "deferred":true, "uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1"}} (at log.go:210)
[NMZ-DBG] 09:59:17.61: EP handling event Signal{map[string]interface {}{"class":"PacketEvent", "option":map[string]interface {}{"src_entity":"localentity-0", "dst_entity":"lo
calentity-0", "value":0}, "type":"event", "deferred":true, "uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1", "entity":"localentity-0"}} (at log.go:210)
[NMZ-DBG] 09:59:17.61: ActionQueue[restentity-3]: Peeking (at log.go:210)
[NMZ-DBG] 09:59:17.61: ActionQueue[restentity-2]: Peeking (at log.go:210)
[NMZ-DBG] 09:59:17.61: MO handling event Signal{map[string]interface {}{"uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1", "entity":"localentity-0", "class":"PacketEvent", "optio
n":map[string]interface {}{"src_entity":"localentity-0", "dst_entity":"localentity-0", "value":0}, "type":"event", "deferred":true}} (at log.go:210)
[NMZ-DBG] 09:59:17.61: MO handled event Signal{map[string]interface {}{"uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1", "entity":"localentity-0", "class":"PacketEvent", "option
":map[string]interface {}{"src_entity":"localentity-0", "dst_entity":"localentity-0", "value":0}, "type":"event", "deferred":true}} (at log.go:210)
[NMZ-DBG] 09:59:17.61: MO sending action Signal{map[string]interface {}{"class":"EventAcceptanceAction", "option":map[string]interface {}{}, "type":"action", "event_uuid":"6e
316b05-572e-47ce-8ed0-a7d9cb1c63c1", "uuid":"92f00b3f-db3a-4d60-8a69-949d950be7bd", "entity":"localentity-0"}} (at log.go:210)
[NMZ-DBG] 09:59:17.61: MO sent action Signal{map[string]interface {}{"uuid":"92f00b3f-db3a-4d60-8a69-949d950be7bd", "entity":"localentity-0", "class":"EventAcceptanceAction",
"option":map[string]interface {}{}, "type":"action", "event_uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1"}} (at log.go:210)
[NMZ-DBG] 09:59:17.61: EP handling action Signal{map[string]interface {}{"uuid":"92f00b3f-db3a-4d60-8a69-949d950be7bd", "entity":"localentity-0", "class":"EventAcceptanceActi
on", "option":map[string]interface {}{}, "type":"action", "event_uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1"}} (at log.go:210)
[NMZ-ERR] 09:59:17.61: Unknown Entity ID:localentity-0 (at log.go:235)
[NMZ-DBG] 09:59:17.61: EP handled action Signal{map[string]interface {}{"uuid":"92f00b3f-db3a-4d60-8a69-949d950be7bd", "entity":"localentity-0", "class":"EventAcceptanceActio
n", "option":map[string]interface {}{}, "type":"action", "event_uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1"}} (at log.go:210)
[NMZ-DBG] 09:59:17.61: EP handled event Signal{map[string]interface {}{"uuid":"6e316b05-572e-47ce-8ed0-a7d9cb1c63c1", "entity":"localentity-0", "class":"PacketEvent", "option
":map[string]interface {}{"src_entity":"localentity-0", "dst_entity":"localentity-0", "value":0}, "type":"event", "deferred":true}} (at log.go:210)