A container is not showing up in VCH but vCenter is still correctly showing it

mdubya66 commented 6 years ago

@arslanabbasi commented on Fri Apr 13 2018

vCenter Server version: 6.5.0.10000
Embedded or external PSC: Embedded
Filename of the OVA you deployed: vic-v1.3.1-3409-132fb13d
Does the VIC appliance receive configuration by DHCP? No, Static
What stage of the Appliance Lifecycle is the VIC appliance in? https://github.com/vmware/vic-product/blob/master/installer/docs/SUPPORT.md#appliance-lifecycle
Attach the VIC appliance support bundle (e.g. vic_appliance_logs_2018-01-01-00-01-00.tar.gz) vic_appliance_logs_2018-04-13-21-42-46.tar.gz

https://github.com/vmware/vic-product/blob/master/installer/docs/SUPPORT.md#appliance-support-bundle Note: The support bundle may contain private information. If you are not comfortable with posting this publicly, please contact VMware GSS.

OPTIONAL, but helpful:

IP address of VIC appliance: 10.40.206.187
Hostname of VIC appliance: vic.tpm.com
IP address of vCenter Server: 10.40.206.195
Hostname of vCenter Server: N/A

Bug Report Detailed Information

What operation was being performed when the failure was noticed? Was checking something else when I realized that a container was not showing up.
Provide information from the Support Information section of the appropriate Appliance Lifecycle stage: https://github.com/vmware/vic-product/blob/master/installer/docs/SUPPORT.md#appliance-lifecycle

The problematic VCH is "vch2-performance". "Log Bundle" and "Log bundle with container logs" for this VCH is attached. The Container VM that is not showing up in "docker --tls ps -a" is bbc-2.

container-logs.zip logs.zip

ubuntu@ubuntu:~/vic/vic-bundle/vic⟫ docker --tls ps -a CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 19b7f0018b17 ubuntu "/bin/bash" 2 hours ago Up 2 hours 192.168.11.32:22->22/tcp, 192.168.11.32:5000-6000->5000-6000/tcp u1 4d844997150f ubuntu "/bin/bash" 2 hours ago Up 2 hours 192.168.11.31:22->22/tcp, 192.168.11.31:5000-6000->5000-6000/tcp u2 7d8b50d601e9 ubuntu "/bin/bash" 2 hours ago Up 2 hours festive_leavitt 4ee83acc6d9a busybox "sh" 3 hours ago Up 3 hours bbc-1 d95121491421 busybox "sh" 3 hours ago Up 3 hours upbeat_hawking

Let me know if anything else is required.

mdubya66 commented 6 years ago

In the portlayer log I see bbc-2 created. I noticed there is a context deadline exceeded for a different container just after bbc-2 was created.

Apr 13 2018 18:48:42.925Z INFO  op=365.1881: Applied naming convention:  resulting bbc-2-0ff70d431cd1
Apr 13 2018 18:48:42.937Z INFO  set log file name to: [prme-haas-vnx7600-01] 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264/tether.debug
Apr 13 2018 18:48:42.937Z INFO  set log file name to: [prme-haas-vnx7600-01] 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264/output.log
Apr 13 2018 18:48:44.944Z INFO  op=365.1887: Reconfigure: attempting update to 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264 with change version "2018-04-13T18:48:44.668467Z" (poweredOff)
Apr 13 2018 18:48:45.338Z INFO  op=365.1887: Reconfigure: committed update to 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264 with change version: 2018-04-13T18:48:44.668467Z
Apr 13 2018 18:48:45.338Z INFO  op=365.1887: Attempting to perform a guest reconfigure operation on (0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264)
Apr 13 2018 18:48:49.244Z WARN  could not refresh endpoint for container 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264: updating endpoint for container 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264: gateway not present for scope external
Apr 13 2018 18:48:49.330Z WARN  could not refresh endpoint for container 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264: updating endpoint for container 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264: gateway not present for scope external
Apr 13 2018 18:48:59.372Z WARN  op=365.1887: container and handle ChangeVersions do not match for 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264: 2018-04-13T18:48:45.812138Z != 2018-04-13T18:48:44.668467Z
Apr 13 2018 18:49:19.535Z INFO  op=365.1907: sending kill -TERM 8d6d82371b0b1b502f04c924b54ac20618074635df8dd34c751a63d8009d4767
Apr 13 2018 18:49:19.587Z INFO  op=365.1907: waiting 10s for 8d6d82371b0b1b502f04c924b54ac20618074635df8dd34c751a63d8009d4767 to power off
Apr 13 2018 18:49:29.535Z ERROR op=365.1907: vic/pkg/trace.(*Operation).Err: shutdown error: context deadline exceeded
vic/lib/portlayer/exec.(*containerBase).shutdown:307 shutdown
vic/lib/apiservers/portlayer/restapi/handlers.(*ContainersHandlersImpl).CommitHandler:218 commit handle(04d746da35eae9a1d28064e8c38ce216)
Apr 13 2018 18:49:29.539Z ERROR op=365.1907: vic/lib/portlayer/exec.(*containerBase).shutdown: shutdown error: context deadline exceeded
vic/lib/portlayer/exec.(*containerBase).shutdown:307 shutdown
vic/lib/apiservers/portlayer/restapi/handlers.(*ContainersHandlersImpl).CommitHandler:218 commit handle(04d746da35eae9a1d28064e8c38ce216)
Apr 13 2018 18:49:29.539Z WARN  op=365.1907: timeout (10s) waiting for 8d6d82371b0b1b502f04c924b54ac20618074635df8dd34c751a63d8009d4767 to power off via SIGTERM
Apr 13 2018 18:49:29.539Z INFO  op=365.1907: sending kill -KILL 8d6d82371b0b1b502f04c924b54ac20618074635df8dd34c751a63d8009d4767
Apr 13 2018 18:49:29.660Z INFO  op=365.1907: waiting 10s for 8d6d82371b0b1b502f04c924b54ac20618074635df8dd34c751a63d8009d4767 to power off
Apr 13 2018 18:49:35.265Z INFO  op=365.1907: Reconfigure: attempting update to 8d6d82371b0b1b502f04c924b54ac20618074635df8dd34c751a63d8009d4767 with change version "2018-04-13T18:47:35.193907Z" (poweredOff)
Apr 13 2018 18:49:35.682Z INFO  op=365.1907: Reconfigure: committed update to 8d6d82371b0b1b502f04c924b54ac20618074635df8dd34c751a63d8009d4767 with change version: 2018-04-13T18:47:35.193907Z
Apr 13 2018 18:49:35.682Z INFO  op=365.1907: Attempting to perform a guest reconfigure operation on (8d6d82371b0b1b502f04c924b54ac20618074635df8dd34c751a63d8009d4767)
Apr 13 2018 18:49:35.682Z WARN  op=365.1907: container and handle PowerStates do not match: poweredOn != poweredOff

A little later on searching for 0ff70d431cd1 there is a portlayer panic in the log

Apr 13 2018 19:56:46.104Z INFO  Established connection with container VM: 486158cf2bfe5a73a71bb4f6ba6f3a59173fea9a404bb326b3ef5e0190828705
Apr 13 2018 21:25:55.740Z INFO  op=365.2406: Reconfigure: attempting update to 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264 with change version "2018-04-13T21:25:49.374495Z" (poweredOn)
Apr 13 2018 21:25:56.195Z INFO  op=365.2406: Reconfigure: committed update to 0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264 with change version: 2018-04-13T21:25:49.374495Z
Apr 13 2018 21:25:56.195Z INFO  op=365.2406: Attempting to perform a guest reconfigure operation on (0ff70d431cd1d95fec9c85916be12544a62bf51a09d2502658961a5c6086c264)
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0xcf3e37]

goroutine 27 [running]:
github.com/vmware/vic/lib/portlayer/exec.(*Container).RefreshFromHandle(0x0, 0x1dd50e0, 0xc420780e10, 0xc4202f24b0, 0x1, 0x1, 0xc4210465b8, 0x8, 0x0, 0xc420cd3c80)
    /go/src/github.com/vmware/vic/lib/portlayer/exec/container.go:361 +0x37
github.com/vmware/vic/lib/portlayer/exec.Commit(0x1dd50e0, 0xc420780e10, 0xc4202f24b0, 0x1, 0x1, 0xc4210465b8, 0x8, 0x0, 0x0, 0xc420cd3c80, ...)
    /go/src/github.com/vmware/vic/lib/portlayer/exec/commit.go:208 +0xf87
github.com/vmware/vic/lib/portlayer/exec.(*Handle).Commit(0xc420cd3c80, 0x1dd50e0, 0xc420780e10, 0xc4202f24b0, 0x1, 0x1, 0xc4210465b8, 0x8, 0x0, 0x0, ...)
    /go/src/github.com/vmware/vic/lib/portlayer/exec/handle.go:241 +0x438
github.com/vmware/vic/lib/portlayer/logging.eventCallback.func1(0x0, 0x0)
    /go/src/github.com/vmware/vic/lib/portlayer/logging/logging.go:84 +0x2fd
github.com/vmware/vic/pkg/retry.DoWithConfig(0xc420780fc0, 0x1378fa0, 0xc4212bbce0, 0x0, 0x0)
    /go/src/github.com/vmware/vic/pkg/retry/retry.go:88 +0x16b
github.com/vmware/vic/pkg/retry.Do(0xc420780fc0, 0x1378fa0, 0x15, 0xc421050100)
    /go/src/github.com/vmware/vic/pkg/retry/retry.go:68 +0xb3
github.com/vmware/vic/lib/portlayer/logging.eventCallback(0x1dd8ac0, 0xc420d26150)
    /go/src/github.com/vmware/vic/lib/portlayer/logging/logging.go:91 +0x3df
github.com/vmware/vic/lib/portlayer/logging.Init.func1.1(0x1dd8ac0, 0xc420d26150)
    /go/src/github.com/vmware/vic/lib/portlayer/logging/logging.go:44 +0x35
github.com/vmware/vic/lib/portlayer/event.newSubscriber.func1(0xc420a094a0)
    /go/src/github.com/vmware/vic/lib/portlayer/event/subscriber.go:113 +0x194
created by github.com/vmware/vic/lib/portlayer/event.newSubscriber
    /go/src/github.com/vmware/vic/lib/portlayer/event/subscriber.go:119 +0x12a
time="2018-04-13T21:25:59Z" level=info msg="Launching portlayer server pprof server on 127.0.0.1:6063" 
time="2018-04-13T21:25:59Z" level=info msg="{Formatter:0xc42069d120 Level:info Syslog:<nil>}" 
Apr 13 2018 21:26:00.254Z INFO  op=2601.3: Creating directory [prme-haas-vnx7600-01] vch2-performance/kvStores
Apr 13 2018 21:26:00.261Z INFO  op=2601.3: Datastore path is [prme-haas-vnx7600-01] vch2-performance/kvStores

hickeng commented 6 years ago

@lcastellano Can you check if this is a dup of the #7322?

vmware / vic

A container is not showing up in VCH but vCenter is still correctly showing it #7743

Bug Report Detailed Information