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.

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

AWS: Master stops responding on t2.micros #18975

Closed
justinsb opened this issue Dec 21, 2015 · 19 comments
Closed

AWS: Master stops responding on t2.micros #18975

justinsb opened this issue Dec 21, 2015 · 19 comments
Labels
area/cloudprovider priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release.
Milestone

Comments

@justinsb
Copy link
Member

I'm trying to break #13997 into its component issues.

An issue which I was able to reproduce: when launching on t2.micros, after a little less than 24 hours, the master stopped responding to kubectl get nodes. I was also unable to SSH in to the instance. When I rebooted the master instance through the AWS API it did come back online (the instance took 30 minutes to reboot, but I don't think that's a k8s issue).

The client was giving a TLS handshake timeout error. I was able to capture the logs after reboot, and noticed these messages shortly before the node went offline:

I1221 14:43:42.656637      10 trace.go:57] Trace "List *api.ServiceList" (started 2015-12-21 14:43:41.200342739 +0000 UTC):
[16.972µs] [16.972µs] About to list etcd node
[858.160862ms] [858.14389ms] Etcd node listed
[1.250900537s] [392.739675ms] Node list decoded
[1.452814222s] [201.913685ms] END
I1221 14:43:42.662117      10 trace.go:57] Trace "List *api.ServiceList" (started 2015-12-21 14:43:41.186539275 +0000 UTC):
[13.794002ms] [13.794002ms] About to list directory
[1.475552892s] [1.46175889s] List extracted
[1.475554865s] [1.973µs] END
I1221 14:43:42.729089      10 trace.go:57] Trace "List *api.EndpointsList" (started 2015-12-21 14:43:41.207543963 +0000 UTC):
[7.815µs] [7.815µs] About to list etcd node
[858.39424ms] [858.386425ms] Etcd node listed
[1.252084981s] [393.690741ms] Node list decoded
[1.417321937s] [165.236956ms] END
I1221 14:43:42.734556      10 trace.go:57] Trace "List *api.EndpointsList" (started 2015-12-21 14:43:41.207537621 +0000 UTC):
[2.661µs] [2.661µs] About to list directory
[1.526977443s] [1.526974782s] List extracted
[1.526980882s] [3.439µs] END
I1221 14:43:48.786497      10 handlers.go:131] GET /api/v1/services: (7.657382831s) 200 [[kube-proxy/v1.1.3 (linux/amd64) kubernetes/6a81b50] 172.20.0.126:51647]
I1221 14:43:51.725595      10 trace.go:57] Trace "List *api.PersistentVolumeList" (started 2015-12-21 14:43:45.667240613 +0000 UTC):
[37.799µs] [37.799µs] About to list etcd node
[4.059455957s] [4.059418158s] Etcd node listed
[4.299796567s] [240.34061ms] Node list decoded
[5.298598648s] [998.802081ms] END
I1221 14:43:51.906564      10 trace.go:57] Trace "List *api.PersistentVolumeList" (started 2015-12-21 14:43:45.996141787 +0000 UTC):
[25.837µs] [25.837µs] About to list etcd node
[3.929678631s] [3.929652794s] Etcd node listed
[4.220383064s] [290.704433ms] Node list decoded
[4.944204619s] [723.821555ms] END
I1221 14:43:52.010993      10 trace.go:57] Trace "List *api.PersistentVolumeList" (started 2015-12-21 14:43:45.986129977 +0000 UTC):
[10.007693ms] [10.007693ms] About to list directory
[6.022202404s] [6.012194711s] List extracted
[6.022205235s] [2.831µs] END

A minute later I got the first of these errors:

I1221 14:44:14.656358      10 logs.go:40] http: TLS handshake error from 172.20.0.127:54092: EOF

Both of those messages started repeating, but then the service appeared to recover for a few minutes, before getting worse again.

Then finally I started seeing this sort of error:

I1221 15:01:14.035065      10 logs.go:40] http: TLS handshake error from 172.20.0.126:51773: EOF
I1221 15:02:08.519787      10 handlers.go:131] GET /api/v1/watch/nodes?fieldSelector=metadata.name%3Dip-172-20-0-126.us-west-2.compute.internal&resourceVersion=32843: (34m20.111665496s) 0 [[kubelet/v1.1.3 (linux/amd64) kubernetes/6a81b50] 172.20.0.126:50117]
I1221 15:02:08.749052      10 handlers.go:131] GET /api/v1/persistentvolumes: (3m7.972076083s) 504
goroutine 101628 [running]:
k8s.io/kubernetes/pkg/httplog.(*respLogger).WriteHeader(0xc20a0ea480, 0x1f8)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/httplog/log.go:188 +0x9a
k8s.io/kubernetes/pkg/apiserver.(*baseTimeoutWriter).timeout(0xc20b03eca0, 0x0, 0x0)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:244 +0xbf
k8s.io/kubernetes/pkg/apiserver.(*timeoutHandler).ServeHTTP(0xc208304060, 0x7fcfc555ea60, 0xc20a0ea480, 0xc20b247ba0)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:168 +0x355
k8s.io/kubernetes/pkg/apiserver.func·013(0x7fcfc555ea28, 0xc209402640, 0xc20b247ba0)
        /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/pkg/apiserver/handlers.go:130 +0x1cb
net/http.HandlerFunc.ServeHTTP(0xc20835f740, 0x7fcfc555ea28, 0xc209402640, 0xc20b247ba0)
        /usr/src/go/src/net/http/server.go:1265 +0x41
net/http.serverHandler.ServeHTTP(0xc208adeea0, 0x7fcfc555ea28, 0xc209402640, 0xc20b247ba0)
        /usr/src/go/src/net/http/server.go:1703 +0x19a
net/http.(*conn).serve(0xc209402460)
        /usr/src/go/src/net/http/server.go:1204 +0xb57
created by net/http.(*Server).Serve
        /usr/src/go/src/net/http/server.go:1751 +0x35e
 [[kube-controller-manager/v1.1.3 (linux/amd64) kubernetes/6a81b50] 127.0.0.1:47162]
I1221 15:01:56.647077      10 logs.go:40] http: TLS handshake error from 172.20.0.128:40481: EOF
I1221 15:02:20.555576      10 handlers.go:131] GET /api/v1/resourcequotas: (2m31.950471878s) 504

And at this point I think the service was simply not responding.

Although I suspected that we have run out of CPU credits (the t2 is burstable), this did not appear to be the case based on the CloudWatch metrics.

I did wonder whether maybe this corresponds to etcd compaction, and there was a compaction around the time, but it appears normal:

2015/12/21 14:58:58 etcdserver: start to snapshot (applied: 200020, lastsnap: 190019)
2015/12/21 14:58:58 etcdserver: compacted log at index 200020
2015/12/21 14:58:58 wal: segmented wal file /var/etcd/data/member/wal/0000000000000014-0000000000030d55.wal is created
2015/12/21 14:58:58 etcdserver: saved snapshot at index 200020
2015/12/21 14:59:00 filePurge: successfully removed file /var/etcd/data/member/wal/000000000000000f-0000000000024a00.wal
2015/12/21 14:59:05 filePurge: successfully removed file /var/etcd/data/member/snap/0000000000000002-00000000000249ff.snap

I captured all of /var/log, but I didn't see anything that leapt out at me as being suspicious.

@justinsb justinsb changed the title AWS: API server stops responding on t2.micros AWS: Master stops responding on t2.micros Dec 21, 2015
@justinsb
Copy link
Member Author

I thought I had lost the error message from kubectl, but I found it:

> kubectl get nodes
error: couldn't read version from server: Get https://<ip>/api: net/http: TLS handshake timeout

@davidopp davidopp added area/cloudprovider team/control-plane priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release. labels Dec 21, 2015
@davidopp
Copy link
Member

@brendandburns

@justinsb
Copy link
Member Author

This happened again on the same cluster. I was unable to SSH in, but this time I just left it alone (did not restart it). Some hours later, it started responding to SSH again, and uptime indicated that it had not rebooted.

Looking at the dmesg output, I can see that kube-apiserver was killed by the OOM killer. (dmesg output below). And then some time later, td-agent was killed by the OOM killer, which is when I presume the machine started responding again.

It might be that 1GB is simply not enough for the master. Or that we should configure some swap space, although I believe we deliberately don't do this because the minute we start swapping we are likely going to go unresponsive anyway.

Also, although kube-apiserver is technically running, the machine is very slow and kube-apiserver is not in practice responsive. The TLS handshakes still timeout. There are long delays logged reading from etcd:

I1222 17:59:31.464621       6 trace.go:57] Trace "List *api.PersistentVolumeClaimList" (started 2015-12-22 17:55:43.302697768 +0000 UTC):
[1.150438337s] [1.150438337s] About to list directory
[3m15.751851678s] [3m14.601413341s] List extracted
[3m19.36164234s] [3.609790662s] END

Unusually (at least to my experience), top shows a lot of time in 'wa' state:

%Cpu(s):  0.0 us,  0.3 sy,  0.0 ni,  0.0 id, 99.4 wa,  0.0 hi,  0.0 si,  0.3 st

dmesg output relating to kube-apiserver kill:

[44981.894779] systemd-journal invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0
[44981.894783] systemd-journal cpuset=system.slice mems_allowed=0
[44981.894787] CPU: 0 PID: 280 Comm: systemd-journal Not tainted 3.19.0-20-generic #20-Ubuntu
[44981.894788] Hardware name: Xen HVM domU, BIOS 4.2.amazon 12/07/2015
[44981.894789]  0000000000000000 ffff880036063898 ffffffff817c3da8 0000000000000007
[44981.894791]  ffff88003931ce80 ffff880036063918 ffffffff817c1ab9 0000000000000000
[44981.894793]  0000000000000000 0000000000000000 0000000000000000 ffff88003c251d70
[44981.894795] Call Trace:
[44981.894801]  [<ffffffff817c3da8>] dump_stack+0x45/0x57
[44981.894815]  [<ffffffff817c1ab9>] dump_header+0x7f/0x1e7
[44981.894819]  [<ffffffff8117e28b>] oom_kill_process+0x22b/0x390
[44981.894822]  [<ffffffff8117e7fd>] out_of_memory+0x24d/0x500
[44981.894824]  [<ffffffff8118474a>] __alloc_pages_nodemask+0xaba/0xba0
[44981.894826]  [<ffffffff811cae71>] alloc_pages_current+0x91/0x110
[44981.894828]  [<ffffffff8117a7a7>] __page_cache_alloc+0xa7/0xd0
[44981.894831]  [<ffffffff8117cebf>] filemap_fault+0x1af/0x400
[44981.894834]  [<ffffffff811a7a4d>] __do_fault+0x3d/0xc0
[44981.894835]  [<ffffffff811aa2ff>] do_read_fault.isra.55+0x1df/0x2f0
[44981.894837]  [<ffffffff811ac1ce>] handle_mm_fault+0x86e/0xff0
[44981.894841]  [<ffffffff81064051>] ? do_page_fault+0x31/0x70
[44981.894842]  [<ffffffff81063c4d>] __do_page_fault+0x1dd/0x5b0
[44981.894846]  [<ffffffff813c2e85>] ? copy_userdebug2: channel 2: window 999310 sent adjust 49266
_enhanced_fast_string+0x5/0x10
[44981.894848]  [<ffffffff81064051>] do_page_fault+0x31/0x70
[44981.894851]  [<ffffffff817cd028>] page_fault+0x28/0x30
[44981.894852] Mem-Info:
[44981.894854] Node 0 DMA per-cpu:
[44981.894855] CPU    0: hi:    0, btch:   1 usd:   0
[44981.894856] Node 0 DMA32 per-cpu:
[44981.894857] CPU    0: hi:  186, btch:  31 usd:  30
[44981.894860] active_anon:215763 inactive_anon:3132 isolated_anon:0
 active_file:581 inactive_file:1023 isolated_file:0
 unevictable:0 dirty:0 writeback:0 unstable:0
 free:12224 slab_reclaimable:4729 slab_unreclaimable:5832
 mapped:822 shmem:3481 pagetables:3586 bounce:0
 free_cma:0
[44981.894862] Node 0 DMA free:4596kB min:704kB low:880kB high:1056kB active_anon:9544kB inactive_anon:172kB active_file:72kB inactive_file:320kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15988kB managed:15904kB mlocked:0kB dirty:0kB writeback:0kB mapped:88kB shmem:224kB slab_reclaimable:188kB slab_unreclaimable:244kB kernel_stack:128kB pagetables:348kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:5068 all_unreclaimable? yes
[44981.894866] lowmem_reserve[]: 0 975 975 975
[44981.894868] Node 0 DMA32 free:44300kB min:44348kB low:55432kB high:66520kB active_anon:853508kB inactive_anon:12356kB active_file:2252kB inactive_file:3772kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1032192kB managed:999304kB mlocked:0kB dirty:0kB writeback:0kB mapped:3200kB shmem:13700kB slab_reclaimable:18728kB slab_unreclaimable:23084kB kernel_stack:6656kB pagetables:13996kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:41028 all_unreclaimable? yes
[44981.894871] lowmem_reserve[]: 0 0 0 0
[44981.894872] Node 0 DMA: 11*4kB (UEM) 11*8kB (UEM) 13*16kB (UEM) 5*32kB (UE) 2*64kB (UE) 3*128kB (UE) 2*256kB (UE) 2*512kB (E) 0*1024kB 1*2048kB (R) 0*4096kB = 4596kB
[44981.894879] Node 0 DMA32: 1529*4kB (UEM) 865*8kB (UEM) 352*16kB (UEM) 177*32kB (EM) 68*64kB (EM) 22*128kB (UEM) 14*256kB (M) 8*512kB (M) 3*1024kB (UM) 1*2048kB (R) 0*4096kB = 44300kB
[44981.894887] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[44981.894888] 5114 total pagecache pages
[44981.894889] 0 pages in swap cache
[44981.894890] Swap cache stats: add 0, delete 0, find 0/0
[44981.894890] Free swap  = 0kB
[44981.894891] Total swap = 0kB
[44981.894892] 262045 pages RAM
[44981.894892] 0 pages HighMem/MovableOnly
[44981.894893] 8243 pages reserved
[44981.894894] 0 pages cma reserved
[44981.894894] 0 pages hwpoisoned
[44981.894895] [ pid ]   uid  tgid total_vm      rss nr_ptes swapents oom_score_adj name
[44981.894898] [  280]     0   280     9409     1426      22        0             0 systemd-journal
[44981.894900] [  302]     0   302    10382      144      22        0         -1000 systemd-udevd
[44981.894901] [  423]     0   423     9304       96      23        0             0 rpcbind
[44981.894903] [  568]     0   568     7115       80      19        0             0 systemd-logind
[44981.894904] [  571]   104   571    65033      707      30        0             0 rsyslogd
[44981.894905] [  597]     0   597     6906       60      17        0             0 cron
[44981.894907] [  608]     0   608   126362    10079     107        0             0 salt-minion
[44981.894908] [  628]     0   628     4930       91      14        0             0 kube-addons.sh
[44981.894909] [  645]     0   645     5866     1726      12        0             0 dhclient
[44981.894916] [  650]     0   650    70819      225      39        0             0 accounts-daemon
[44981.894917] [  667]     0   667    48105     9289      95        0             0 salt-master
[44981.894919] [  671]     0   671     4795       40      14        0             0 atd
[44981.894920] [  687]     0   687   171863    14312      93        0          -999 kubelet
[44981.894921] [  701]   105   701    10593      122      25        0          -900 dbus-daemon
[44981.894923] [  731]     0   731    69671      175      39        0             0 polkitd
[44981.894924] [ 1049]   111  1049     7884      152      19        0             0 ntpd
[44981.894925] [ 1347]     0  1347    14910      170      33        0         -1000 sshd
[44981.894927] [ 1358]     0  1358     3599       41      12        0             0 agetty
[44981.894928] [ 1359]     0  1359     3644       40      12        0             0 agetty
[44981.894929] [ 1480]     0  1480    57454    18423     114        0             0 salt-master
[44981.894931] [ 1481]     0  1481    55598     5461      73        0             0 salt-master
[44981.894932] [ 1482]     0  1482    55598     5526      73        0             0 salt-master
[44981.894933] [ 2041]     0  2041   109945    10002     103        0             0 salt-master
[44981.894934] [ 2042]     0  2042    48105     9290      92        0             0 salt-master
[44981.894936] [ 2045]     0  2045    92105    11487     105        0             0 salt-master
[44981.894937] [ 2046]     0  2046   112461    11404     108        0             0 salt-master
[44981.894938] [ 2047]     0  2047   128908    11438     110        0             0 salt-master
[44981.894939] [ 2048]     0  2048   112589    11510     109        0             0 salt-master
[44981.894940] [ 2049]     0  2049    91977    11401     105        0             0 salt-master
[44981.894942] [ 2050]     0  2050   142353     9407     103        0             0 salt-master
[44981.894943] [ 2238]     0  2238   260688     4344      89        0          -900 docker
[44981.894944] [ 2848]     0  2848      956      243       7        0          -999 pause
[44981.894945] [ 2859]     0  2859      956      243       8        0          -999 pause
[44981.894947] [ 2860]     0  2860      956      244       8        0          -999 pause
[44981.894948] [ 2863]     0  2863      956      243       7        0          -999 pause
[44981.894949] [ 2864]     0  2864      956      244       8        0          -999 pause
[44981.894950] [ 2875]     0  2875      956      243       7        0          -999 pause
[44981.894952] [ 2958]     0  2958      793        9       7        0          1000 sh
[44981.894953] [ 2976]     0  2976     4917     1180      14        0          1000 kube-scheduler
[44981.894954] [ 3048]     0  3048      793        8       7        0          1000 sh
[44981.894956] [ 3060]     0  3060    10492     4069      24        0          1000 kube-controller
[44981.894957] [ 3075]     0  3075      793        9       7        0          1000 sh
[44981.894958] [ 3100]     0  3100    25279     5157      54        0          1000 td-agent
[44981.894959] [ 3111]     0  3111    39658    30862      81        0          1000 kube-apiserver
[44981.894961] [ 4508]     0  4508   183355    30067     124        0          1000 td-agent
[44981.894962] [25360]     0 25360    23395      232      47        0             0 sshd
[44981.894963] [25362]  1000 25362    10656      148      25        0             0 systemd
[44981.894964] [25363]  1000 25363    14598      388      32        0             0 (sd-pam)
[44981.894966] [25462]  1000 25462     5482      645      15        0             0 bash
[44981.894967] [26228]  1000 26228     6424       65      16        0             0 screen
[44981.894968] [26229]  1000 26229     6593      249      16        0             0 screen
[44981.894970] [26230]  1000 26230     5456      627      15        0             0 bash
[44981.894971] [26267]  1000 26267     1496       29       7        0             0 tail
[44981.894972] [26268]  1000 26268     2054       46       9        0             0 grep
[44981.894974] [ 1025]  1000  1025     5456      627      16        0             0 bash
[44981.894975] [16219]     0 16219      793        9       7        0          1000 sh
[44981.894976] [16220]     0 16220      793        8       7        0          1000 sh
[44981.894977] [16229]     0 16229    16583     6908      28        0          1000 etcd
[44981.894979] [16230]     0 16230     5220     1808      14        0          1000 etcd
[44981.894980] [ 8898]     0  8898     4956      116      14        0             0 kube-addon-upda
[44981.894981] [ 8899]     0  8899     4964      127      13        0             0 kube-addon-upda
[44981.894983] [ 8900]     0  8900     4965      128      13        0             0 kube-addon-upda
[44981.894984] [ 9200]     0  9200     4966      127      13        0             0 kube-addon-upda
[44981.894985] [ 9201]     0  9201     4966      127      13        0             0 kube-addon-upda
[44981.894986] [ 9202]     0  9202     4966      127      13        0             0 kube-addon-upda
[44981.894987] [ 9203]     0  9203     4966      127      13        0             0 kube-addon-upda
[44981.894989] [ 9204]     0  9204     4966      127      13        0             0 kube-addon-upda
[44981.894990] [ 9205]     0  9205     4966      127      13        0             0 kube-addon-upda
[44981.894991] [ 9241]     0  9241     4967      128      13        0             0 kube-addon-upda
[44981.894992] [ 9242]     0  9242     4967      128      13        0             0 kube-addon-upda
[44981.894994] [ 9243]     0  9243     4967      128      13        0             0 kube-addon-upda
[44981.894995] [ 9244]     0  9244     4967      128      13        0             0 kube-addon-upda
[44981.894996] [ 9245]     0  9245     4967      128      13        0             0 kube-addon-upda
[44981.894997] [ 9246]     0  9246     4967      128      13        0             0 kube-addon-upda
[44981.894998] [ 9247]     0  9247     4967      128      13        0             0 kube-addon-upda
[44981.895000] [ 9274]     0  9274    68886     1546      32        0             0 kubectl
[44981.895001] [ 9275]     0  9275    68886     1051      32        0             0 kubectl
[44981.895002] [ 9276]     0  9276    68886     1546      33        0             0 kubectl
[44981.895016] [ 9277]     0  9277    68886     1560      34        0             0 kubectl
[44981.895017] [ 9278]     0  9278    68886     1574      32        0             0 kubectl
[44981.895019] [ 9279]     0  9279    68886     1281      32        0             0 kubectl
[44981.895020] [ 9317]     0  9317    68886     1287      32        0             0 kubectl
[44981.895021] [ 9318]     0  9318    68886     1542      32        0             0 kubectl
[44981.895022] [ 9319]     0  9319    49364      413      28        0             0 kubectl
[44981.895023] [ 9320]     0  9320    68886     1549      32        0             0 kubectl
[44981.895024] [ 9321]     0  9321    68886     1057      32        0             0 kubectl
[44981.895026] [ 9322]     0  9322    68886     2053      32        0             0 kubectl
[44981.895027] [ 9323]     0  9323    68886     1320      31        0             0 kubectl
[44981.895028] [ 9476]     0  9476     1118       36       7        0             0 dhclient-script
[44981.895029] [ 9477]     0  9477    13313       87      27        0             0 sshd
[44981.895030] [ 9480]     0  9480    10587       77      24        0             0 cron
[44981.895031] [ 9481]     0  9481    13313       73      27        0             0 sshd
[44981.895032] [ 9484]     0  9484     3226       40      12        0             0 resolvconf
[44981.895034] [ 9485]     0  9485    13313       72      27        0             0 sshd
[44981.895035] [ 9486]     0  9486     9556       68      22        0             0 cron
[44981.895036] [ 9487]     0  9487    13313       70      28        0             0 sshd
[44981.895037] [ 9489]     0  9489    13313       71      27        0             0 sshd
[44981.895038] [ 9490]     0  9490   126362    10083     103        0             0 salt-minion
[44981.895039] [ 9491]     0  9491    13313       70      26        0             0 sshd
[44981.895041] [ 9492]     0  9492    13310       63      26        0             0 sshd
[44981.895042] [ 9493]     0  9493    13308       61      27        0             0 sshd
[44981.895043] [ 9494]     0  9494    12252       57      24        0             0 sshd
[44981.895044] [ 9495]     0  9495    11167       53      22        0             0 sshd
[44981.895045] [ 9496]     0  9496    10624       50      21        0             0 sshd
[44981.895046] [ 9497]     0  9497     5040       26      12        0             0 sshd
[44981.895047] [ 9498]     0  9498    14910      170      31        0         -1000 sshd
[44981.895048] Out of memory: Kill process 3111 (kube-apiserver) score 1118 or sacrifice child
[44981.899355] Killed process 3111 (kube-apiserver) total-vm:158632kB, anon-rss:123448kB, file-rss:0kB

@kristofferpeterhansel
Copy link

Yeah. We the same problem where it is very obviously running out of memory and becomes unresponsive since it cannot swap.

I've been looking at some sort of information on what the expected memory usage is supposed to be. But haven't found any information on it. Are there any thoughts from the team if this is simply too small a machine to run it on?

@Roconda
Copy link

Roconda commented Jan 18, 2016

T2.micro might be too limited for kubernetes. When running kubernetes on AWS for a testing period of 24h the master node was reaching the CPU credit limit constantly without heavy load on the cluster. And after a while it stops responding.
I'll try to spin up a cluster with other instance types.

@kristofferpeterhansel
Copy link

Currently we run a test cluster with etcd running on t2.nano instances and Kubernetes running on t2.small. And it seems to just exactly work. When Kubernetes does a lot of stuff it does get fairly close to the memory limit on both the node types. But so far it hasn't broken

@petermd
Copy link
Contributor

petermd commented Jan 21, 2016

Have also seen this issue on a fresh run w/default configuration. Could eventually get back into master but docker was unresponsive and had to reboot to recover. There were no swap / diskspace issues but iowait was >90%

CloudWatch accounting suggests the master is running down its CPUCredits so probably will underperform but there is one thing that might be amplifying the problem.

a) liveness checks are failing due to "use of closed network connection" causing apiserver in particular to occasionally get restarted

b) the kube-addon-update script retry mechanism means it will continually retry (up to 60 times per 10 minute cycle) to validate each addon (you can see 16 instances running in the ps dump from @justinsb above) with no backoff. this means it can be running constantly during a slowdown

c) the script appears to be constantly executing kubectl create commands, i don't fully understand how it works, but is it possible that because the script cannot query the available addons (eg when api server is slow / restarting) that it will assume the addon needs to be re-created and keep stopping / restarting all the addon containers?

there are long sequences of (taking ES as an example, but all 14 are having the same issue concurrently)

Jan 20 12:54:20 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T12:54:20+0000. 8 tries remaining. ==
Jan 20 12:54:33 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T12:54:33+0000. 56 tries remaining. ==
Jan 20 12:54:33 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T12:54:33+0000. 7 tries remaining. ==
Jan 20 13:16:10 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:16:10+0000. 55 tries remaining. ==
Jan 20 13:16:10 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:16:10+0000. 6 tries remaining. ==
Jan 20 13:16:57 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:16:57+0000. 54 tries remaining. ==
Jan 20 13:16:57 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:16:57+0000. 5 tries remaining. ==
Jan 20 13:18:18 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:18:18+0000. 4 tries remaining. ==
Jan 20 13:18:18 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:18:18+0000. 53 tries remaining. ==
Jan 20 13:19:01 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:19:01+0000. 3 tries remaining. ==
Jan 20 13:19:02 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:19:01+0000. 52 tries remaining. ==
Jan 20 13:19:50 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:19:50+0000. 2 tries remaining. ==
Jan 20 13:19:50 ip-172-20-0-9 kube-addons.sh[18972]: INFO: == Failed to execute /usr/local/bin/kubectl create --namespace=kube-system -f /etc/kubernetes/addons/fluentd-elasticsearch/es-controller.yaml at 2016-01-20T13:19:50+0000. 51 tries remaining. ==
.
.
.

note the interleaved tries remaining suggest there are two passes over-lapping so each service is being validated twice concurrently

nb not suggesting this is the root-cause, but it might be part of the reason the server becomes completely unresponsive?

@petermd
Copy link
Contributor

petermd commented Jan 27, 2016

found a problem (#20219) that causes kube-addon-update to get stuck in retry death-spin if it runs when apiserver is slow responding, temporarily fixing that and changing the salt-master worker.threads to 2 seems to be enough to keep the master node mostly available.

it's still burning down its CPUCreditBalance slightly though so it will be too sluggish for anything other then test usage, but at least it stays online for a few days!

@nawazdhandala
Copy link

I have the same problem. However rebooting the instance and waiting for it to settle fixes this temporarily (and it does failsafter few hours).

@Cptn727
Copy link

Cptn727 commented Feb 2, 2016

We've also had experiences similar to above. With a t2.micro master, it will eventually go unresponsive. Often within 24 hours, sometimes longer. When unresponsive, we cannot use API or SSH, and are forced to issue a reboot from AWS directly. Cloudwatch suggests we did not exhaust CPU credits, but on the one or two times we've been lucky enough to be on the box, memory exhaustion seems to be the culprit. We've just recently transitioned the master to t2.small, and so far no problems, but it's been less than a day.

@nawazdhandala
Copy link

How is it now? Does it still respond?

@carolinebeauchamp
Copy link

I've been running on a t2.small instance for several days now with no particular problem, having had problems on a t2.micro instance.

@nawazdhandala
Copy link

Thank you so much. I'll try on a small instance.

@petermd
Copy link
Contributor

petermd commented Feb 4, 2016

Making the two changes I mentioned above, the master has been up for 12 days now and is still responsive (only light usage however).

I see several instances in the log where the add-on update failed. Would suggest checking for

Kubernetes addon update completed with errors

in the t2.small syslog just in case

The minions died (NotReady, ssh timed out, needed reboot) however - have not investigated why.

@nawazdhandala
Copy link

I'm using Google Cloud. They have a managed service for Kubernetes and it seems to do fairly good.

@justinsb justinsb modified the milestone: v1.2 Feb 10, 2016
@davidopp
Copy link
Member

@justinsb I see you added v1.2 milestone. Do you think you will have time to look into this in the next few days?

@justinsb
Copy link
Member Author

@davidopp yes - I'd like to address this with #21151

@justinsb
Copy link
Member Author

I've split this into two issues:

  1. We should have more memory for the master: AWS: Use m3.medium for the master by default #21151 & AWS: Change master to m3.medium by default #21160
  2. If the kubelet or any other crucial component gets killed, we should restart it: AWS: Make sure docker/kubelet/kube-proxy auto-restart in systemd #21162

@petermd
Copy link
Contributor

petermd commented Feb 12, 2016

For large clusters the bigger spec. is probably worthwhile (esp. if scaling the master is hard), but maybe worth noting that with the fix for #20219 and smaller number of salt-master threads the master has ran for 3 weeks on a t2.micro test cluster without this problem re-occuring.

justinsb added a commit to justinsb/kubernetes that referenced this issue Feb 17, 2016
m3.large for > 150 nodes.

t2.micro often runs out of memory.  The t2 class has very
difficult-to-understand behaviour when it runs out of CPU.  The
m3.medium is reasonably affordable, and avoids these problems.

Fix kubernetes#21151

Issue kubernetes#18975
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/cloudprovider priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release.
Projects
None yet
Development

No branches or pull requests

9 participants