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

[attach] could it be that the exit event is being returned to the client before the output and the client terminates at that point #4166

Closed
mdubya66 opened this issue Mar 7, 2017 · 4 comments
Closed

[attach] could it be that the exit event is being returned to the client before the output and the client terminates at that point #4166

mdubya66 opened this issue Mar 7, 2017 · 4 comments
Labels
area/kernel kind/defect Behavior that is inconsistent with what's intended priority/p2

Comments

@mdubya66
Copy link
Contributor

mdubya66 commented Mar 7, 2017 •
edited by caglar10ur

See #3858
There is a periodic failure in the added test: https://ci.vmware.run/vmware/vic/8458

output.log for the container shows the expected output:

FOUND

tether.debug shows that we're attached by the time the output is written:

Mar  7 2017 04:30:52.238Z DEBUG binding reader/writers for channel for 58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d
Mar  7 2017 04:30:52.240Z DEBUG Adding [0xc4200803c0] to Outwriter
Mar  7 2017 04:30:52.240Z DEBUG [0xc4201a0f90] added writer - now 3 writers
Mar  7 2017 04:30:52.241Z DEBUG [0xc4201a0f90] Writer 0 [0xc42000e148]
Mar  7 2017 04:30:52.242Z DEBUG [0xc4201a0f90] Writer 1 [0xc42000e018]
Mar  7 2017 04:30:52.243Z DEBUG [0xc4201a0f90] Writer 2 [0xc4200803c0]
Mar  7 2017 04:30:52.244Z DEBUG Adding [0xc4200803c0] to Reader
Mar  7 2017 04:30:52.245Z DEBUG [0xc4201a4780] added reader - now 1 readers
Mar  7 2017 04:30:52.246Z DEBUG [0xc4201a4780] Reader 0 [0xc4200803c0]
Mar  7 2017 04:30:52.247Z DEBUG reader/writers bound for channel for 58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d
Mar  7 2017 04:30:52.249Z DEBUG Unblocking the launch of 58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d
Mar  7 2017 04:30:52.250Z DEBUG [BEGIN] [main.(*attachServerSSH).channelMux:519] attach server channel request handler
Mar  7 2017 04:30:52.251Z DEBUG Unblocked the launch of 58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d
Mar  7 2017 04:30:52.251Z DEBUG Received the clear signal to launch 58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d
Mar  7 2017 04:30:52.258Z DEBUG [BEGIN] [github.com/vmware/vic/lib/tether.establishPty:223] initializing pty handling for session 58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d
Mar  7 2017 04:30:52.263Z DEBUG [ END ] [github.com/vmware/vic/lib/tether.establishPty:223] [4.393987ms] initializing pty handling for session 58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d
Mar  7 2017 04:30:52.267Z DEBUG Launched command with pid 212
Mar  7 2017 04:30:52.268Z DEBUG [0xc4201a0f90] write "FOUND\r\n" to 3 writers (err: <nil>)
Mar  7 2017 04:30:52.270Z WARN  Wait returned waitid: no child processes
Mar  7 2017 04:30:52.276Z DEBUG [ END ] [github.com/vmware/vic/lib/tether.(*tether).launch:507] [497.98244ms] launching session 58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d
Mar  7 2017 04:30:52.280Z DEBUG GuestInfoSink: error: <nil>
Mar  7 2017 04:30:52.286Z DEBUG Tags: "vic:\"0.1\" scope:\"read-write\" key:\"diagnostics\""
Mar  7 2017 04:30:52.287Z DEBUG Scopes: []string{"read-write"}
Mar  7 2017 04:30:52.289Z DEBUG Key specified: diagnostics
Mar  7 2017 04:30:52.291Z DEBUG Key: guestinfo.vice..sessions|58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d.diagnostics, Kind: struct Value: <executor.Diagnostics Value>
Mar  7 2017 04:30:52.294Z DEBUG Encoding object: executor.Diagnostics{DebugLevel:0, ResurrectionCount:0, ExitLogs:[]executor.ExitLog{}}
Mar  7 2017 04:30:52.297Z DEBUG Tags: "vic:\"0.1\" scope:\"read-only\" key:\"debug\""
Mar  7 2017 04:30:52.299Z DEBUG Scopes: []string{"read-only"}
Mar  7 2017 04:30:52.301Z DEBUG Key specified: debug
Mar  7 2017 04:30:52.303Z DEBUG Key: guestinfo.vice./sessions|58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d/diagnostics/debug, Kind: int Value: <int Value>
Mar  7 2017 04:30:52.306Z DEBUG Tags: "vic:\"0.1\" scope:\"read-write\" key:\"resurrections\""
Mar  7 2017 04:30:52.307Z DEBUG Scopes: []string{"read-write"}
Mar  7 2017 04:30:52.309Z DEBUG Key specified: resurrections
Mar  7 2017 04:30:52.310Z DEBUG Key: guestinfo.vice..sessions|58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d.diagnostics.resurrections, Kind: int Value: <int Value>
Mar  7 2017 04:30:52.313Z DEBUG GuestInfoSink: setting key: guestinfo.vice..sessions|58b97fec97426f7e8f274f10f80445664a8e790690faf27bd40a53f97d19ce5d.diagnostics.resurrections, value: "0"
Mar  7 2017 04:30:52.280Z DEBUG Cleanup on detach from the session
Mar  7 2017 04:30:52.318Z DEBUG Removing [0xc4200803c0] from Outwriter
Mar  7 2017 04:30:52.318Z DEBUG [0xc4201a0f90] removing writer 0xc4200803c0 - currently 3 writers
Mar  7 2017 04:30:52.319Z DEBUG [0xc4201a0f90] removed writer - now 2 writers
Mar  7 2017 04:30:52.320Z DEBUG [0xc4201a0f90] Writer 0 [0xc42000e148]
Mar  7 2017 04:30:52.321Z DEBUG [0xc4201a0f90] Writer 1 [0xc42000e018]
Mar  7 2017 04:30:52.322Z DEBUG Removing [0xc4200803c0] from Reader
Mar  7 2017 04:30:52.323Z DEBUG [0xc4201a4780] removing reader - currently 1 readers
Mar  7 2017 04:30:52.324Z DEBUG [0xc4201a4780] removed reader - now 0 readers
Mar  7 2017 04:30:52.325Z DEBUG [ END ] [main.(*attachServerSSH).channelMux:519] [74.648683ms] attach server channel request handler
Mar  7 2017 04:30:52.280Z DEBUG [0xc4201a4780] removing reader due to EOF
Mar  7 2017 04:30:52.327Z DEBUG [0xc4201a4780] removing reader - currently 0 readers
Mar  7 2017 04:30:52.328Z DEBUG [0xc4201a4780] read "" from 1 readers (err: <nil>)
Mar  7 2017 04:30:52.328Z DEBUG [0xc4201a4780] read from closed multi-reader, returning EOF
Mar  7 2017 04:30:52.329Z DEBUG [0xc4201a4780] read "" from 0 readers (err: &errors.errorString{s:"EOF"})
Mar  7 2017 04:30:52.330Z DEBUG PTY stdin copy: %!s(<nil>)

This looks a lot like output not being completely flushed - speculation, but could it be that the exit event is being returned to the client before the output and the client terminates at that point @sflxn ?
@mhagen-vmware mhagen-vmware added priority/p0 kind/defect Behavior that is inconsistent with what's intended labels Mar 9, 2017
@cgtexmex cgtexmex self-assigned this Mar 15, 2017
@cgtexmex cgtexmex added this to the Sprint 5 milestone Mar 15, 2017
@cgtexmex
Copy link
Contributor

https://ci.vmware.run/vmware/vic/8790
https://ci.vmware.run/vmware/vic/8778

Two more examples of the issue -- cc @hmahmood

@cgtexmex cgtexmex assigned hmahmood and unassigned cgtexmex Mar 21, 2017
@mhagen-vmware
Copy link
Contributor

integration_logs_8778_ff14beadd481cae362c3af4f76637e93ccbd12cf.zip
integration_logs_8790_91d8720677b46900f4de8f705f04f0ee817345c5.zip

@hmahmood hmahmood mentioned this issue Mar 23, 2017
Closed
@mhagen-vmware mhagen-vmware modified the milestones: Sprint 6, Sprint 5 Mar 29, 2017
@caglar10ur
Copy link
Contributor

I believe #4339 will fix this

@mhagen-vmware mhagen-vmware removed this from the Sprint 6 milestone Apr 12, 2017
@mdubya66 mdubya66 changed the title could it be that the exit event is being returned to the client before the output and the client terminates at that point [attach] could it be that the exit event is being returned to the client before the output and the client terminates at that point Apr 12, 2017
@corrieb
Copy link
Contributor

corrieb commented Jul 18, 2017 •
edited

I think it's safe to close this. If we were still seeing this test failure, we would know about it. It's part of our CI. There were many many improvements made to exec attach around that time.

@corrieb corrieb closed this as completed Jul 18, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/kernel kind/defect Behavior that is inconsistent with what's intended priority/p2
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@caglar10ur @cgtexmex @corrieb @hmahmood @mdubya66 @mhagen-vmware