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

Probe hammers app with pipe requests after deletion failure #1114

Closed
2opremio opened this issue Mar 3, 2016 · 3 comments · Fixed by #1172
Closed

Probe hammers app with pipe requests after deletion failure #1114

2opremio opened this issue Mar 3, 2016 · 3 comments · Fixed by #1172
Assignees
@tomwilkie
Labels
bug Broken end user or developer functionality; not working as the developers intended it
Milestone
0.14.0

Comments

@2opremio
Copy link
Contributor

2opremio commented Mar 3, 2016

While testing #1101 with the service, when I stop a session with ^D or exit, the window doesn't close (I need to close it clicking on the cross on the terminal window) and the probe starts requesting /api/pipe/pipeID/probe in a loop.

Here are the logs of the frontend/app/probe when opening a terminal, closing it with '^D' and then forcibly closing the terminal window:

Commented frontend logs:

### User opens terminal and app connects to pipe
172.17.42.1 - - [03/Mar/2016:16:00:09 +0000] "GET /api/app/little-frog-59/api/pipe/pipe-2894880524980326857/check HTTP/1.1" 200 0 "https://scope.weave.works/api/app/little-frog-59/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/48.0.2564.116 Safari/537.36"

### Probe connects to pipe
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 3 "-" "Go-http-client/1.1"

# User disconnects through '^D', I guess that the probe notices and stops the terminal
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "DELETE /api/pipe/pipe-2894880524980326857 HTTP/1.1" 405 172 "-" "Go-http-client/1.1"

# Probe gets crazy and starts requesting the probe in a loop?
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:14 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:15 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 101 0 "-" "Go-http-client/1.1"

## [...] truncated

## UI's terminal window is manually closed
172.17.42.1 - - [03/Mar/2016:16:00:18 +0000] "DELETE /api/app/little-frog-59/api/pipe/pipe-2894880524980326857 HTTP/1.1" 200 0 "https://scope.weave.works/api/app/little-frog-59/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/48.0.2564.116 Safari/537.36"

## probe tries to reconnect (using backoff I believe)
172.17.42.1 - - [03/Mar/2016:16:00:18 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 404 19 "-" "Go-http-client/1.1"
172.17.42.1 - - [03/Mar/2016:16:00:19 +0000] "GET /api/pipe/pipe-2894880524980326857/probe HTTP/1.1" 404 19 "-" "Go-http-client/1.1"

Commented app logs:

## app opens pipes
<app> INFO: 2016/03/03 16:00:09.642545 Creating pipe id pipe-2894880524980326857
<app> INFO: 2016/03/03 16:00:09.643044 Pipe success pipe-2894880524980326857 (1)
<app> INFO: 2016/03/03 16:00:09.855740 Pipe success pipe-2894880524980326857 (0)

## Probe connecting in a loop?
<app> INFO: 2016/03/03 16:00:14.419953 Pipe success pipe-2894880524980326857 (1)
<app> INFO: 2016/03/03 16:00:14.432784 Error copying to pipe pipe-2894880524980326857 (1) websocket: websocket: close 1006 (abnormal closure): unexpected EOF
<app> INFO: 2016/03/03 16:00:14.494639 Pipe success pipe-2894880524980326857 (1)
<app> INFO: 2016/03/03 16:00:14.496018 Error copying to pipe pipe-2894880524980326857 (1) websocket: websocket: close 1006 (abnormal closure): unexpected EOF
<app> INFO: 2016/03/03 16:00:14.601878 Pipe success pipe-2894880524980326857 (1)
<app> INFO: 2016/03/03 16:00:14.604569 Error copying to pipe pipe-2894880524980326857 (1) websocket: websocket: close 1006 (abnormal closure): unexpected EOF
<app> INFO: 2016/03/03 16:00:14.722011 Pipe success pipe-2894880524980326857 (1)
<app> INFO: 2016/03/03 16:00:14.734063 Error copying to pipe pipe-2894880524980326857 (1) websocket: websocket: close 1006 (abnormal closure): unexpected EOF
<app> INFO: 2016/03/03 16:00:14.798855 Pipe success pipe-2894880524980326857 (1)
<app> INFO: 2016/03/03 16:00:14.816817 Error copying to pipe pipe-2894880524980326857 (1) websocket: websocket: close 1006 (abnormal closure): unexpected EOF
<app> INFO: 2016/03/03 16:00:14.924466 Pipe success pipe-2894880524980326857 (1)
<app> INFO: 2016/03/03 16:00:14.952492 Error copying to pipe pipe-2894880524980326857 (1) websocket: websocket: close 1006 (abnormal closure): unexpected EOF
<app> INFO: 2016/03/03 16:00:14.996152 Pipe success pipe-2894880524980326857 (1)
<app> INFO: 2016/03/03 16:00:15.013590 Error copying to pipe pipe-2894880524980326857 (1) websocket: websocket: close 1006 (abnormal closure): unexpected EOF
### [...] truncated

## App closes pipe due to closed window
<app> INFO: 2016/03/03 16:00:18.195287 Closing pipe pipe-2894880524980326857

Probe logs:

<probe> INFO: 2016/03/03 16:00:09.605700 Pipe pipe-2894880524980326857 connection to 10.0.0.52:80 starting
<probe> INFO: 2016/03/03 16:00:13.182899 Exec on container bcdc40194ee24da39a5db549cd28192d0df8a58f80b4f63453fafa3b79835c29 closed.
<probe> ERRO: 2016/03/03 16:00:18.304253 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 1s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:00:19.333125 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 2s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:00:21.346724 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 4s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:00:25.375004 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 8s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:00:33.398791 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 16s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:00:45.063868 Error collecting weave info, backing off 1m0s: Get http://127.0.0.1:6784/report: dial tcp 127.0.0.1:6784: getsockopt: connection refused
<probe> ERRO: 2016/03/03 16:00:49.429689 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 32s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:01:21.492236 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 1m0s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:02:21.545297 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 1m0s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:03:21.565044 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 1m0s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:04:21.578589 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 1m0s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:05:21.598825 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 1m0s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:06:21.630312 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 1m0s: websocket: bad handshake
<probe> ERRO: 2016/03/03 16:07:21.678606 Error doing pipe-2894880524980326857 for 10.0.0.52:80, backing off 1m0s: websocket: bad handshake
@2opremio
Copy link
Contributor Author

2opremio commented Mar 3, 2016

OK, I think I know what's happening:

172.17.42.1 - - [03/Mar/2016:16:00:13 +0000] "DELETE /api/pipe/pipe-2894880524980326857 HTTP/1.1" 405 172 "-" "Go-http-client/1.1"

The 405 is probably coming from the app-mapper. I forgot to allow the DELETE method for that endpoint.

However, the probe shouldn't go bananas when that endpoint fails.

@2opremio 2opremio changed the title Service: can't implicitly close terminals ('^D/exit') Probe hammers app with pipe creations after deletion failure Mar 3, 2016
@2opremio 2opremio mentioned this issue Mar 3, 2016
Merged
@2opremio 2opremio added the bug Broken end user or developer functionality; not working as the developers intended it label Mar 3, 2016
@2opremio 2opremio changed the title Probe hammers app with pipe creations after deletion failure Probe hammers app with pipe requests after deletion failure Mar 3, 2016
@errordeveloper errordeveloper mentioned this issue Mar 4, 2016
Closed
@2opremio 2opremio mentioned this issue Mar 5, 2016
Closed
@foot
Copy link
Contributor

foot commented Mar 7, 2016

I think we've fixed this one w/ #1099? @2opremio?

@foot
Copy link
Contributor

foot commented Mar 7, 2016

Sorry sorry I didn't read the issues properly, this seems like a diff issue.

@tomwilkie tomwilkie mentioned this issue Mar 15, 2016
Merged
@tomwilkie tomwilkie added this to the 0.14.0 milestone Mar 24, 2016
@tomwilkie tomwilkie self-assigned this Mar 24, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@tomwilkie tomwilkie

Labels
bug Broken end user or developer functionality; not working as the developers intended it
Projects
None yet
Milestone
0.14.0
Development

Successfully merging a pull request may close this issue.

Various websocket and pipe fixes. weaveworks/scope
3 participants
@foot @tomwilkie @2opremio