Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

TestRouter HTTP server failed: accept tcp 172.18.4.111:8889: use of closed network connection #13426

Closed
enj opened this issue Mar 17, 2017 · 2 comments
Closed

TestRouter HTTP server failed: accept tcp 172.18.4.111:8889: use of closed network connection #13426

enj opened this issue Mar 17, 2017 · 2 comments
Assignees
@knobunc
Labels
component/networking kind/bug Categorizes issue or PR as related to a bug. kind/test-flake Categorizes issue or PR as related to test flakes. lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. priority/P1

Comments

@enj
Copy link
Contributor

enj commented Mar 17, 2017 

14:12:08 Running TestRootRedirect...
14:12:12 ok      TestRootRedirect
14:12:12 Running TestRouter...
14:12:47 failed  TestRouter
14:12:47 I0317 14:12:13.071930   24079 router_http_server.go:358] Started, serving at 172.18.4.111:8080
14:12:47 I0317 14:12:13.072017   24079 router_http_server.go:358] Started, serving at 172.18.4.111:8888
14:12:47 I0317 14:12:13.072079   24079 router_http_server.go:358] Started, serving at 172.18.4.111:8889
14:12:47 I0317 14:12:13.072630   24079 router_http_server.go:390] Started, serving TLS at 172.18.4.111:8443
14:12:47 I0317 18:12:14.534666       1 reflector.go:185] Starting reflector *api.Service (10m0s) from github.com/openshift/origin/pkg/router/template/service_lookup.go:30
14:12:47 I0317 18:12:14.538161       1 reflector.go:234] Listing and watching *api.Service from github.com/openshift/origin/pkg/router/template/service_lookup.go:30
14:12:47 I0317 18:12:14.555549       1 router.go:140] Creating a new template router, writing to /var/lib/haproxy/router
14:12:47 I0317 18:12:14.555591       1 router.go:289] Template router will coalesce reloads within 1 seconds of each other
14:12:47 I0317 18:12:14.555607       1 router.go:347] Writing default certificate to /var/lib/haproxy/router/certs
14:12:47 I0317 18:12:14.558361       1 router.go:185] Reading persisted state
14:12:47 I0317 18:12:14.558392       1 router.go:189] Committing state
14:12:47 I0317 18:12:14.558404       1 router.go:390] Writing the router state
14:12:47 I0317 18:12:14.560190       1 router.go:395] Writing the router config
14:12:47 I0317 18:12:14.561090       1 router.go:400] Reloading the router
14:12:47 I0317 18:12:14.754791       1 router.go:475] Router reloaded:
14:12:47  - Checking HAProxy /healthz on port 1936 ...
14:12:47  - HAProxy port 1936 health check ok : 0 retry attempt(s).
14:12:47 I0317 18:12:14.754865       1 router.go:236] Router is including routes in all namespaces
14:12:47 I0317 18:12:14.754967       1 reflector.go:185] Starting reflector *api.Route (10m0s) from github.com/openshift/origin/pkg/router/controller/factory/factory.go:68
14:12:47 I0317 18:12:14.755011       1 reflector.go:185] Starting reflector *api.Endpoints (10m0s) from github.com/openshift/origin/pkg/router/controller/factory/factory.go:75
14:12:47 I0317 18:12:14.755054       1 controller.go:70] Running router controller
14:12:47 I0317 18:12:14.755075       1 reaper.go:17] Launching reaper
14:12:47 I0317 18:12:14.755091       1 reflector.go:234] Listing and watching *api.Route from github.com/openshift/origin/pkg/router/controller/factory/factory.go:68
14:12:47 I0317 18:12:14.755223       1 reflector.go:234] Listing and watching *api.Endpoints from github.com/openshift/origin/pkg/router/controller/factory/factory.go:75
14:12:47 I0317 18:12:14.757443       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:14.757539       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:14.757604       1 plugin.go:151] Processing 1 Endpoints for Name: example (ADDED)
14:12:47 I0317 18:12:14.757631       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:14.757757       1 plugin.go:163] Modifying endpoints for rotorouter/example
14:12:47 I0317 18:12:14.757787       1 controller.go:296] Router sync in progress
14:12:47 I0317 18:12:14.757831       1 controller.go:305] Processing Route: rotorouter/example -> example
14:12:47 I0317 18:12:14.757841       1 controller.go:306]            Alias: unsecure.example.com
14:12:47 I0317 18:12:14.757845       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:14.757850       1 controller.go:308]            Event: ADDED
14:12:47 I0317 18:12:14.757857       1 router.go:129] host unsecure.example.com admitted
14:12:47 I0317 18:12:14.757996       1 unique_host.go:195] Route rotorouter/example claims unsecure.example.com
14:12:47 I0317 18:12:14.758031       1 status.go:179] has last touch <nil> for rotorouter/example
14:12:47 I0317 18:12:14.758081       1 status.go:269] admit: admitting route by updating status: example (true): unsecure.example.com
14:12:47 I0317 18:12:14.759143       1 router.go:696] Adding route rotorouter/example
14:12:47 I0317 18:12:14.759160       1 controller.go:298] Router sync complete
14:12:47 I0317 18:12:14.759167       1 router.go:374] Router state synchronized for the first time
14:12:47 I0317 18:12:14.759226       1 router.go:390] Writing the router state
14:12:47 I0317 18:12:14.760759       1 router.go:395] Writing the router config
14:12:47 I0317 18:12:14.762600       1 router.go:400] Reloading the router
14:12:47 I0317 18:12:14.786592       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:14.786666       1 reaper.go:32] Reaped process with pid 31
14:12:47 I0317 18:12:14.796495       1 router.go:475] Router reloaded:
14:12:47  - Checking HAProxy /healthz on port 1936 ...
14:12:47  - HAProxy port 1936 health check ok : 0 retry attempt(s).
14:12:47 I0317 18:12:14.796508       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:14.859257       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:14.859319       1 controller.go:305] Processing Route: rotorouter/example -> example
14:12:47 I0317 18:12:14.859330       1 controller.go:306]            Alias: unsecure.example.com
14:12:47 I0317 18:12:14.859378       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:14.859385       1 controller.go:308]            Event: DELETED
14:12:47 I0317 18:12:14.859398       1 router.go:129] host unsecure.example.com admitted
14:12:47 I0317 18:12:14.859438       1 unique_host.go:211] Deleting routes for rotorouter/example
14:12:47 I0317 18:12:14.859455       1 plugin.go:191] Deleting route rotorouter/example
14:12:47 I0317 18:12:14.859490       1 plugin.go:151] Processing 1 Endpoints for Name: example (DELETED)
14:12:47 I0317 18:12:14.859510       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:14.859550       1 plugin.go:168] Deleting endpoints for rotorouter/example
14:12:47 I0317 18:12:14.859257       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:14.859851       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:14.859965       1 plugin.go:151] Processing 1 Endpoints for Name: example-path (ADDED)
14:12:47 I0317 18:12:14.859990       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:14.860034       1 plugin.go:163] Modifying endpoints for rotorouter/example-path
14:12:47 I0317 18:12:14.863246       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:14.863339       1 controller.go:305] Processing Route: rotorouter/example-path -> example-path
14:12:47 I0317 18:12:14.863345       1 controller.go:306]            Alias: unsecure.example.com
14:12:47 I0317 18:12:14.863349       1 controller.go:307]            Path: /test
14:12:47 I0317 18:12:14.863353       1 controller.go:308]            Event: ADDED
14:12:47 I0317 18:12:14.863359       1 router.go:129] host unsecure.example.com admitted
14:12:47 I0317 18:12:14.863381       1 unique_host.go:195] Route rotorouter/example-path claims unsecure.example.com
14:12:47 I0317 18:12:14.863391       1 status.go:179] has last touch <nil> for rotorouter/example-path
14:12:47 I0317 18:12:14.863413       1 status.go:269] admit: admitting route by updating status: example-path (true): unsecure.example.com
14:12:47 I0317 18:12:14.864274       1 router.go:696] Adding route rotorouter/example-path
14:12:47 I0317 18:12:14.964975       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:14.965008       1 plugin.go:151] Processing 1 Endpoints for Name: example-path (DELETED)
14:12:47 I0317 18:12:14.965020       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:14.965059       1 plugin.go:168] Deleting endpoints for rotorouter/example-path
14:12:47 I0317 18:12:14.965094       1 controller.go:305] Processing Route: rotorouter/example-path -> example-path
14:12:47 I0317 18:12:14.965101       1 controller.go:306]            Alias: unsecure.example.com
14:12:47 I0317 18:12:14.965106       1 controller.go:307]            Path: /test
14:12:47 I0317 18:12:14.965112       1 controller.go:308]            Event: DELETED
14:12:47 I0317 18:12:14.965129       1 router.go:129] host unsecure.example.com admitted
14:12:47 I0317 18:12:14.965169       1 unique_host.go:211] Deleting routes for rotorouter/example-path
14:12:47 I0317 18:12:14.965182       1 plugin.go:191] Deleting route rotorouter/example-path
14:12:47 I0317 18:12:14.964975       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:14.965585       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:14.965674       1 plugin.go:151] Processing 2 Endpoints for Name: example-preferred-port (ADDED)
14:12:47 I0317 18:12:14.965689       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8889, Protocol:"TCP"}}}
14:12:47 I0317 18:12:14.965714       1 plugin.go:154]   Subset 1 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:14.965731       1 plugin.go:163] Modifying endpoints for rotorouter/example-preferred-port
14:12:47 I0317 18:12:14.965960       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:14.966120       1 controller.go:305] Processing Route: rotorouter/example-preferred-port -> example-preferred-port
14:12:47 I0317 18:12:14.966138       1 controller.go:306]            Alias: pref.port.unsecure.example.com
14:12:47 I0317 18:12:14.966144       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:14.966150       1 controller.go:308]            Event: ADDED
14:12:47 I0317 18:12:14.966159       1 router.go:129] host pref.port.unsecure.example.com admitted
14:12:47 I0317 18:12:14.966195       1 unique_host.go:195] Route rotorouter/example-preferred-port claims pref.port.unsecure.example.com
14:12:47 I0317 18:12:14.966210       1 status.go:179] has last touch <nil> for rotorouter/example-preferred-port
14:12:47 I0317 18:12:14.966261       1 status.go:269] admit: admitting route by updating status: example-preferred-port (true): pref.port.unsecure.example.com
14:12:47 I0317 18:12:14.967442       1 router.go:696] Adding route rotorouter/example-preferred-port
14:12:47 I0317 18:12:15.555814       1 router.go:390] Writing the router state
14:12:47 I0317 18:12:15.556179       1 router.go:395] Writing the router config
14:12:47 I0317 18:12:15.558153       1 router.go:400] Reloading the router
14:12:47 I0317 18:12:15.591482       1 router.go:475] Router reloaded:
14:12:47  - Checking HAProxy /healthz on port 1936 ...
14:12:47  - HAProxy port 1936 health check ok : 0 retry attempt(s).
14:12:47 I0317 18:12:15.591520       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:15.667486       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:15.667538       1 plugin.go:151] Processing 2 Endpoints for Name: example-preferred-port (DELETED)
14:12:47 I0317 18:12:15.667552       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8889, Protocol:"TCP"}}}
14:12:47 I0317 18:12:15.667582       1 plugin.go:154]   Subset 1 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:15.667602       1 plugin.go:168] Deleting endpoints for rotorouter/example-preferred-port
14:12:47 I0317 18:12:15.667643       1 controller.go:305] Processing Route: rotorouter/example-preferred-port -> example-preferred-port
14:12:47 I0317 18:12:15.667663       1 controller.go:306]            Alias: pref.port.unsecure.example.com
14:12:47 I0317 18:12:15.667668       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:15.667672       1 controller.go:308]            Event: DELETED
14:12:47 I0317 18:12:15.667684       1 router.go:129] host pref.port.unsecure.example.com admitted
14:12:47 I0317 18:12:15.667721       1 unique_host.go:211] Deleting routes for rotorouter/example-preferred-port
14:12:47 I0317 18:12:15.667742       1 plugin.go:191] Deleting route rotorouter/example-preferred-port
14:12:47 I0317 18:12:15.667503       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:15.668469       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:15.668585       1 plugin.go:151] Processing 1 Endpoints for Name: example-edge (ADDED)
14:12:47 I0317 18:12:15.668600       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:15.668619       1 plugin.go:163] Modifying endpoints for rotorouter/example-edge
14:12:47 I0317 18:12:15.669186       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:15.669306       1 controller.go:305] Processing Route: rotorouter/example-edge -> example-edge
14:12:47 I0317 18:12:15.669318       1 controller.go:306]            Alias: edge.example.com
14:12:47 I0317 18:12:15.669323       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:15.669326       1 controller.go:308]            Event: ADDED
14:12:47 I0317 18:12:15.669333       1 router.go:129] host edge.example.com admitted
14:12:47 I0317 18:12:15.669355       1 unique_host.go:195] Route rotorouter/example-edge claims edge.example.com
14:12:47 I0317 18:12:15.670502       1 status.go:179] has last touch <nil> for rotorouter/example-edge
14:12:47 I0317 18:12:15.670530       1 status.go:269] admit: admitting route by updating status: example-edge (true): edge.example.com
14:12:47 I0317 18:12:15.674435       1 router.go:696] Adding route rotorouter/example-edge
14:12:47 I0317 18:12:16.555818       1 router.go:390] Writing the router state
14:12:47 I0317 18:12:16.556289       1 router.go:395] Writing the router config
14:12:47 I0317 18:12:16.558195       1 router.go:400] Reloading the router
14:12:47 I0317 18:12:16.594061       1 router.go:475] Router reloaded:
14:12:47  - Checking HAProxy /healthz on port 1936 ...
14:12:47  - HAProxy port 1936 health check ok : 0 retry attempt(s).
14:12:47 I0317 18:12:16.594095       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:16.674471       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:16.674695       1 plugin.go:151] Processing 1 Endpoints for Name: example-edge (DELETED)
14:12:47 I0317 18:12:16.674745       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:16.674723       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:16.674772       1 plugin.go:168] Deleting endpoints for rotorouter/example-edge
14:12:47 I0317 18:12:16.674919       1 controller.go:305] Processing Route: rotorouter/example-edge -> example-edge
14:12:47 I0317 18:12:16.674933       1 controller.go:306]            Alias: edge.example.com
14:12:47 I0317 18:12:16.674940       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:16.674946       1 controller.go:308]            Event: DELETED
14:12:47 I0317 18:12:16.674957       1 router.go:129] host edge.example.com admitted
14:12:47 I0317 18:12:16.674996       1 unique_host.go:211] Deleting routes for rotorouter/example-edge
14:12:47 I0317 18:12:16.675735       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:16.676166       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:16.676574       1 plugin.go:191] Deleting route rotorouter/example-edge
14:12:47 I0317 18:12:16.676719       1 plugin.go:151] Processing 1 Endpoints for Name: example-edge-path (ADDED)
14:12:47 I0317 18:12:16.676731       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:16.676769       1 plugin.go:163] Modifying endpoints for rotorouter/example-edge-path
14:12:47 I0317 18:12:16.676898       1 controller.go:305] Processing Route: rotorouter/example-edge-path -> example-edge-path
14:12:47 I0317 18:12:16.676910       1 controller.go:306]            Alias: edge.example.com
14:12:47 I0317 18:12:16.676916       1 controller.go:307]            Path: /test
14:12:47 I0317 18:12:16.676922       1 controller.go:308]            Event: ADDED
14:12:47 I0317 18:12:16.676930       1 router.go:129] host edge.example.com admitted
14:12:47 I0317 18:12:16.676963       1 unique_host.go:195] Route rotorouter/example-edge-path claims edge.example.com
14:12:47 I0317 18:12:16.678468       1 status.go:179] has last touch <nil> for rotorouter/example-edge-path
14:12:47 I0317 18:12:16.678497       1 status.go:269] admit: admitting route by updating status: example-edge-path (true): edge.example.com
14:12:47 I0317 18:12:16.679422       1 router.go:696] Adding route rotorouter/example-edge-path
14:12:47 I0317 18:12:16.780172       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:16.780375       1 plugin.go:151] Processing 1 Endpoints for Name: example-edge-path (DELETED)
14:12:47 I0317 18:12:16.780398       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8888, Protocol:"TCP"}}}
14:12:47 I0317 18:12:16.780431       1 plugin.go:168] Deleting endpoints for rotorouter/example-edge-path
14:12:47 I0317 18:12:16.780547       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:16.780732       1 controller.go:305] Processing Route: rotorouter/example-edge-path -> example-edge-path
14:12:47 I0317 18:12:16.780742       1 controller.go:306]            Alias: edge.example.com
14:12:47 I0317 18:12:16.780748       1 controller.go:307]            Path: /test
14:12:47 I0317 18:12:16.780754       1 controller.go:308]            Event: DELETED
14:12:47 I0317 18:12:16.780765       1 router.go:129] host edge.example.com admitted
14:12:47 I0317 18:12:16.780794       1 unique_host.go:211] Deleting routes for rotorouter/example-edge-path
14:12:47 I0317 18:12:16.782346       1 plugin.go:191] Deleting route rotorouter/example-edge-path
14:12:47 I0317 18:12:16.782384       1 certmanager.go:163] attempted to delete file /var/lib/haproxy/router/certs/rotorouter_example-edge-path.pem but it does not exist
14:12:47 I0317 18:12:16.783258       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:16.783399       1 controller.go:305] Processing Route: rotorouter/example-reencrypt -> example-reencrypt
14:12:47 I0317 18:12:16.783409       1 controller.go:306]            Alias: reencrypt.example.com
14:12:47 I0317 18:12:16.783415       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:16.783421       1 controller.go:308]            Event: ADDED
14:12:47 I0317 18:12:16.783430       1 router.go:129] host reencrypt.example.com admitted
14:12:47 I0317 18:12:16.783463       1 unique_host.go:195] Route rotorouter/example-reencrypt claims reencrypt.example.com
14:12:47 I0317 18:12:16.785148       1 status.go:179] has last touch <nil> for rotorouter/example-reencrypt
14:12:47 I0317 18:12:16.785176       1 status.go:269] admit: admitting route by updating status: example-reencrypt (true): reencrypt.example.com
14:12:47 I0317 18:12:16.785686       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:16.786016       1 router.go:696] Adding route rotorouter/example-reencrypt
14:12:47 I0317 18:12:16.786031       1 router.go:702] Creating new frontend for key: rotorouter/example-reencrypt
14:12:47 I0317 18:12:16.786068       1 plugin.go:151] Processing 1 Endpoints for Name: example-reencrypt (ADDED)
14:12:47 I0317 18:12:16.786078       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8443, Protocol:"TCP"}}}
14:12:47 I0317 18:12:16.786101       1 plugin.go:163] Modifying endpoints for rotorouter/example-reencrypt
14:12:47 I0317 18:12:17.555816       1 router.go:390] Writing the router state
14:12:47 I0317 18:12:17.556370       1 router.go:395] Writing the router config
14:12:47 I0317 18:12:17.585981       1 router.go:400] Reloading the router
14:12:47 I0317 18:12:17.619870       1 router.go:475] Router reloaded:
14:12:47  - Checking HAProxy /healthz on port 1936 ...
14:12:47  - HAProxy port 1936 health check ok : 0 retry attempt(s).
14:12:47 I0317 18:12:17.619960       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:17.687268       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:17.687583       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:75: Watch close - *api.Endpoints total 1 items received
14:12:47 I0317 18:12:17.687720       1 controller.go:305] Processing Route: rotorouter/example-reencrypt -> example-reencrypt
14:12:47 I0317 18:12:17.687728       1 controller.go:306]            Alias: reencrypt.example.com
14:12:47 I0317 18:12:17.687732       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:17.687736       1 controller.go:308]            Event: DELETED
14:12:47 I0317 18:12:17.687745       1 router.go:129] host reencrypt.example.com admitted
14:12:47 I0317 18:12:17.687779       1 unique_host.go:211] Deleting routes for rotorouter/example-reencrypt
14:12:47 E0317 18:12:17.688319       1 runtime.go:64] Observed a panic: "Invalid state transition: DELETED -> ADDED" (Invalid state transition: DELETED -> ADDED)
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/util/runtime/runtime.go:70
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/util/runtime/runtime.go:63
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/util/runtime/runtime.go:49
14:12:47 /usr/local/go/src/runtime/asm_amd64.s:479
14:12:47 /usr/local/go/src/runtime/panic.go:458
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/pkg/client/cache/eventqueue.go:132
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/pkg/client/cache/eventqueue.go:196
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/client/cache/reflector.go:370
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/client/cache/reflector.go:317
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/client/cache/reflector.go:187
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/util/wait/wait.go:96
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/util/wait/wait.go:97
14:12:47 /go/src/github.com/openshift/origin/_output/local/go/src/github.com/openshift/origin/vendor/k8s.io/kubernetes/pkg/util/wait/wait.go:52
14:12:47 /usr/local/go/src/runtime/asm_amd64.s:2086
14:12:47 I0317 18:12:17.688925       1 reflector.go:392] github.com/openshift/origin/pkg/router/controller/factory/factory.go:68: Watch close - *api.Route total 1 items received
14:12:47 I0317 18:12:17.689070       1 plugin.go:191] Deleting route rotorouter/example-reencrypt
14:12:47 I0317 18:12:17.689246       1 plugin.go:151] Processing 1 Endpoints for Name: example-reencrypt (DELETED)
14:12:47 I0317 18:12:17.689255       1 plugin.go:154]   Subset 0 : api.EndpointSubset{Addresses:[]api.EndpointAddress{api.EndpointAddress{IP:"172.18.4.111", Hostname:"", NodeName:(*string)(nil), TargetRef:(*api.ObjectReference)(nil)}}, NotReadyAddresses:[]api.EndpointAddress(nil), Ports:[]api.EndpointPort{api.EndpointPort{Name:"", Port:8443, Protocol:"TCP"}}}
14:12:47 I0317 18:12:17.689285       1 plugin.go:168] Deleting endpoints for rotorouter/example-reencrypt
14:12:47 I0317 18:12:17.689316       1 controller.go:305] Processing Route: rotorouter/example-reencrypt -> example-reencrypt
14:12:47 I0317 18:12:17.689327       1 controller.go:306]            Alias: allow.reencrypt.example.com
14:12:47 I0317 18:12:17.689334       1 controller.go:307]            Path: 
14:12:47 I0317 18:12:17.689339       1 controller.go:308]            Event: ADDED
14:12:47 I0317 18:12:17.689346       1 router.go:129] host allow.reencrypt.example.com admitted
14:12:47 I0317 18:12:17.689379       1 unique_host.go:195] Route rotorouter/example-reencrypt claims allow.reencrypt.example.com
14:12:47 I0317 18:12:17.690974       1 status.go:179] has last touch <nil> for rotorouter/example-reencrypt
14:12:47 I0317 18:12:17.691006       1 status.go:269] admit: admitting route by updating status: example-reencrypt (true): allow.reencrypt.example.com
14:12:47 I0317 18:12:17.691571       1 router.go:696] Adding route rotorouter/example-reencrypt
14:12:47 I0317 18:12:18.555815       1 router.go:390] Writing the router state
14:12:47 I0317 18:12:18.556429       1 router.go:395] Writing the router config
14:12:47 I0317 18:12:18.558779       1 router.go:400] Reloading the router
14:12:47 I0317 18:12:18.592491       1 router.go:475] Router reloaded:
14:12:47  - Checking HAProxy /healthz on port 1936 ...
14:12:47  - HAProxy port 1936 health check ok : 0 retry attempt(s).
14:12:47 I0317 18:12:18.592523       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:18.688611       1 reflector.go:234] Listing and watching *api.Endpoints from github.com/openshift/origin/pkg/router/controller/factory/factory.go:75
14:12:47 I0317 18:12:44.967442       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:44.967508       1 reaper.go:32] Reaped process with pid 56
14:12:47 I0317 18:12:45.669107       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:45.669167       1 reaper.go:32] Reaped process with pid 80
14:12:47 I0317 18:12:46.782179       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:46.782250       1 reaper.go:32] Reaped process with pid 104
14:12:47 I0317 18:12:47.689698       1 reaper.go:24] Signal received: child exited
14:12:47 I0317 18:12:47.689761       1 reaper.go:32] Reaped process with pid 128
14:12:47 I0317 14:12:47.960933   24079 router_http_server.go:258] Stopping listener at 172.18.4.111:8080
14:12:47 I0317 14:12:47.960978   24079 router_http_server.go:258] Stopping listener at 172.18.4.111:8888
14:12:47 I0317 14:12:47.960990   24079 router_http_server.go:258] Stopping listener at 172.18.4.111:8889
14:12:47 I0317 14:12:47.960999   24079 router_http_server.go:258] Stopping listener at 172.18.4.111:8443
14:12:47 
--- FAIL: TestRouter (34.89s)
14:12:47 	router_test.go:355: TC non-secure: url 0.0.0.0 alias unsecure.example.com protocol http
14:12:47 	router_test.go:355: TC non-secure-path: url 0.0.0.0/test alias unsecure.example.com protocol http
14:12:47 	router_test.go:355: TC preferred-port: url 0.0.0.0 alias pref.port.unsecure.example.com protocol http
14:12:47 	router_test.go:355: TC edge termination: url 0.0.0.0 alias edge.example.com protocol https
14:12:47 	router_test.go:355: TC edge termination path: url 0.0.0.0/test alias edge.example.com protocol https
14:12:47 	router_test.go:355: TC reencrypt: url 0.0.0.0 alias reencrypt.example.com protocol https
14:12:47 	router_test.go:355: TC reencrypt-InsecureEdgePolicy: url 0.0.0.0 alias allow.reencrypt.example.com protocol http
14:12:47 	router_test.go:357: TC reencrypt-InsecureEdgePolicy failed: unavailable the entire time: endpoint not available
14:12:47 	router_test.go:363: You may need to add an entry to /etc/hosts so that the hostname of the router (allow.reencrypt.example.com) resolves its the IP address, (0.0.0.0).
14:12:47 FAIL
14:12:47 E0317 14:12:47.961077   24079 router_http_server.go:364] HTTP server failed: accept tcp 172.18.4.111:8889: use of closed network connection
14:12:47 Running TestRouterBindsPortsAfterSync...
14:12:50 ok      TestRouterBindsPortsAfterSync

https://ci.openshift.redhat.com/jenkins/job/test_pull_request_origin_integration/416/consoleFull#-80309608656bf4006e4b05b79524e5923
@enj enj added the kind/test-flake Categorizes issue or PR as related to test flakes. label Mar 17, 2017
@enj
Copy link
Contributor Author

enj commented Mar 17, 2017

cc @openshift/networking

@enj enj mentioned this issue Mar 17, 2017
Merged
@pweil- pweil- added component/networking kind/bug Categorizes issue or PR as related to a bug. labels Mar 20, 2017
@mfojtik mfojtik mentioned this issue Apr 19, 2017
Merged
@miminar miminar mentioned this issue May 15, 2017
Merged
@miminar miminar mentioned this issue Jun 26, 2017
Merged
@csrwng csrwng mentioned this issue Aug 31, 2017
Merged
@openshift-bot
Copy link
Contributor

Issues go stale after 90d of inactivity.

Mark the issue as fresh by commenting /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.
Exclude this issue from closing by commenting /lifecycle frozen.

If this issue is safe to close now please do so with /close.

/lifecycle stale

@openshift-ci-robot openshift-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Feb 9, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@knobunc knobunc

Labels
component/networking kind/bug Categorizes issue or PR as related to a bug. kind/test-flake Categorizes issue or PR as related to test flakes. lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. priority/P1
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@openshift-bot @0xmichalis @pweil- @enj @knobunc @openshift-ci-robot