From users-return-268733-archive-asf-public=cust-asf.ponee.io@tomcat.apache.org Tue Nov 12 11:27:22 2019 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [207.244.88.153]) by mx-eu-01.ponee.io (Postfix) with SMTP id AABB0180656 for ; Tue, 12 Nov 2019 12:27:21 +0100 (CET) Received: (qmail 55394 invoked by uid 500); 12 Nov 2019 11:27:17 -0000 Mailing-List: contact users-help@tomcat.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: "Tomcat Users List" Delivered-To: mailing list users@tomcat.apache.org Received: (qmail 55382 invoked by uid 99); 12 Nov 2019 11:27:17 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd2-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 12 Nov 2019 11:27:17 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd2-us-west.apache.org (ASF Mail Server at spamd2-us-west.apache.org) with ESMTP id A31F11A420A for ; Tue, 12 Nov 2019 11:27:16 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd2-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 0.001 X-Spam-Level: X-Spam-Status: No, score=0.001 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, HTML_MESSAGE=0.2, RCVD_IN_DNSWL_NONE=-0.0001, SPF_HELO_NONE=0.001, SPF_PASS=-0.001, URIBL_BLOCKED=0.001] autolearn=disabled Authentication-Results: spamd2-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com Received: from mx1-he-de.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id 6Mzb7e_UcZ-h for ; Tue, 12 Nov 2019 11:27:14 +0000 (UTC) Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=2607:f8b0:4864:20::144; helo=mail-il1-x144.google.com; envelope-from=manmedia@gmail.com; receiver= Received: from mail-il1-x144.google.com (mail-il1-x144.google.com [IPv6:2607:f8b0:4864:20::144]) by mx1-he-de.apache.org (ASF Mail Server at mx1-he-de.apache.org) with ESMTPS id 1CC617DD69 for ; Tue, 12 Nov 2019 11:27:14 +0000 (UTC) Received: by mail-il1-x144.google.com with SMTP id u17so10313036ilq.5 for ; Tue, 12 Nov 2019 03:27:14 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:references:in-reply-to:from:date:message-id:subject:to; bh=iRYw7sGBQanxU6RgLAGuGbPjtmTN8Rp6W4OPNCc1B+Y=; b=FsDD97DIqeZZXgKIDjBvJwlpNz8ifSf848+Ovk1QlQLVNueY4ROT9WNBCu8jtCZydh jwyj/qGAJ3QLZ4h4QAFRJCn3PpSrsq2wsVe+N+ka/Wt+ON7DvTub8bh/zP2ZUlw+8XWo 7xo3z1FEHIvwUy6PK9Ps6dmm+SxWME3FQu80VSdf6Fg/vLJbowa5MfmwEFoXH+OwWhB8 jqekxfCwdC1mbgDX/8ETBeDwdMApxdGDC5oK5351eqcseK01mJ9bN5Ydwszp1oIeq/rl +deVFwrYoH8Vu0zs7l7/cmNoBu7/jSli51VgF7QBUGd+IRdX0fqa/4NdOZZdxlOwe34e tASg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to; bh=iRYw7sGBQanxU6RgLAGuGbPjtmTN8Rp6W4OPNCc1B+Y=; b=d545XuYGZQOEM11HgK821qGH1/82J3p/5RMazATTtgLcvDYZRM+n6IaZIyqyWP6Fv6 xbtrWMXPYeHneMrBZCUzpaoMU2jfJA+UzOO8E1fpv6e8v8+AZFAEW+1h4iN9YxdMuP4s rFB1K6/3i95uMtMAwjBjLnrkCCNekDF8gcxYwT6VQP0fM9Ao+e/Z/YcftHv83UNRFLE0 /eWJMmQojLs9Kr35ZyTpMU500NfrRdUv6hpKmP83m3soWDxodlNHI1ltIaa1ZK5QuLQ7 /2UHnzdJ48wWetwSHkAtA4C5wzbfjskoxyB1o6xUCyeGHYuRkWZHkT2sClO+LEj3bjwc MuvQ== X-Gm-Message-State: APjAAAVX71440/Xbt82fqPy+4SNAWjngks7mUJeOboCFLDkrN9V0+XLP a3Y30kvjuJAiKKla48qzuxSdNtLu3nZIR/0WydoXeCpPf1Aw2g== X-Google-Smtp-Source: APXvYqyk3DmSWwfJhXiJ6Ocv11yzMcusD9ivjmDq0JuA+pNLPCpEq8hlGUtAQTHcS1Sh/jHIsF61nfayohu1sf6gNHA= X-Received: by 2002:a92:8c1c:: with SMTP id o28mr34009767ild.34.1573558032518; Tue, 12 Nov 2019 03:27:12 -0800 (PST) MIME-Version: 1.0 References: <0F7034A9-A36D-4782-A3EC-48F58F4A5B72@apache.org> In-Reply-To: <0F7034A9-A36D-4782-A3EC-48F58F4A5B72@apache.org> From: "M. Manna" Date: Tue, 12 Nov 2019 11:27:01 +0000 Message-ID: Subject: Re: tomcat thread incurring CPU load To: Tomcat Users List Content-Type: multipart/alternative; boundary="0000000000008fd55d05972487b5" --0000000000008fd55d05972487b5 Content-Type: text/plain; charset="UTF-8" Hey Mark (appreciate your response in US holiday time) On Tue, 12 Nov 2019 at 07:51, Mark Thomas wrote: > On November 12, 2019 12:54:53 AM UTC, "M. Manna" > wrote: > >Just to give an update again: > > > >1) We reverted the APR to 1.2.21 - but observed no difference. > >2) We took 3 thread dumps over 1 min interval (without any user > >sessions) - > >All threads are tomcat's internal pool threads. > > > >When we checked the thread details (using fasthread.io) - we didn't see > >any > >of our application stack. Since there is no user traffic, this is > >coming > >from tomcat internally. At this stage, we cannot really figure out > >what's > >the root cause. > > > >Any help is appreciated. > > Migrated from what (full version info please)? > from 8.5.41 to 8.5.45 (we migrate 3 times a year, last was in June) > > Operating system exact version? > Microsoft Windows Server 2016 DataCentre (64-bit) > > JRE vendor and exact version? > C:\jdk1.8.0\bin>java.exe -version java version "1.8.0_162" Java(TM) SE Runtime Environment (build 1.8.0_162-b12) Java HotSpot(TM) 64-Bit Server VM (build 25.162-b12, mixed mode) > Do you see the same behavior with the latest 8.5.x and latest Tomcat > Native? > We are using APR 1.2.23 which I can also see in latest tomcat. Due to production due diligence we cannot roll to a different version that easily. Normally, we lag behind by 2 monthly releases of tomcat. We also reverted the APR to 1.2.21 (but no difference). > > What triggers this behaviour? > That is quite strange. Due to US holidays, we had a low traffic on our servers, and nothing has crept in to suggest that it's application-driven. We took one tomcat instance out of 50 instances and removed all user sessions (i.e. no application activities or threads). Upon restart of tomcat, the CPU spike lingered past the initial servlet startup period. We monitored that over 1-2 hours but there was no difference. > > How often do you see this behaviour? > We took 2 sets of data 1) 3 Jstack dump based on 10 seconds interval. 2) 3 jstack dump based on 1 min interval. Both the above reveals that all background threads (http, pool etc.) were from tomcat. We didn't have any application threads lingered in those 3 samples. So yes we see this almost all the time if we take samples. However, when we compared with pre-production instances (with Windows server R2 x64 bit), we don't see such abnormal spike. In fact, the application instance doesn't incur such a big CPU spike. Whilst composing this email, I am now thinking if the APR is indeed incompatible with WIndows Server R2 (or the presence of any Windows Updates) which blocks the native poll() call longer than usual. An example is that on Windows Server 2012 - APR poll() call takes about 30% CPU time - but with Windows Server 2016 it's almost always 95%. > > And anything else you think might be relevant. > We are using end-2-end encryption using APR (with Certificate and SSLConfig resource setup in server.xml). But it's survived past 3 tomcat upgrades without any issue. Except OS we don't have any obvious culprit identified at the moment. Thanks, > > Mark > > > > >Thanks, > > > >On Mon, 11 Nov 2019 at 20:57, M. Manna wrote: > > > >> Hello All, > >> > >> Any thoughts regarding this? Slightly clueless at this point, so any > >> direction will be appreciated. > >> > >> We are seeing the poll taking all the CPU time. We are using > >> OperatingSystemMXBean.getProcessCpuLoad() and > >> OperatingSystemMXBean.getSystemCpuLoad() to get our metrics (then > >x100 to > >> get the pct). > >> > >> Thanks, > >> > >> > >> On Mon, 11 Nov 2019 at 17:46, M. Manna wrote: > >> > >>> Hello, > >>> > >>> after migrating to 8.5.45, we are seeing a lot of cpu load by > >following > >>> JVM thread dump: > >>> > >>> "https-openssl-apr-0.0.0.0-8443-Poller" : 102 : RUNNABLE : > >>> cpu=172902703125000 : cpuLoad= 74.181015 > >>> > >>> BlockedCount:8464 BlockedTime:0 LockName:null LockOwnerID:-1 > >>> LockOwnerName:null > >>> > >>> WaitedCount:5397 WaitedTime:0 InNative:false IsSuspended:false at > >>> org.apache.tomcat.jni.Poll.poll(Poll.java:-2) > >>> > >>> at > >>> > >org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1547) > >>> > >>> at java.lang.Thread.run(Thread.java:748) > >>> > >>> > >>> These are coming after 2-3 successful jvm dump. Is this something > >>> familiar to anybody? > >>> > >>> Thanks, > >>> > >> > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org > For additional commands, e-mail: users-help@tomcat.apache.org > > --0000000000008fd55d05972487b5--