Return-Path: X-Original-To: apmail-logging-log4j-dev-archive@www.apache.org Delivered-To: apmail-logging-log4j-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 1DDC318619 for ; Fri, 8 Apr 2016 04:50:26 +0000 (UTC) Received: (qmail 48321 invoked by uid 500); 8 Apr 2016 04:50:25 -0000 Delivered-To: apmail-logging-log4j-dev-archive@logging.apache.org Received: (qmail 48261 invoked by uid 500); 8 Apr 2016 04:50:25 -0000 Mailing-List: contact log4j-dev-help@logging.apache.org; run by ezmlm Precedence: bulk List-Unsubscribe: List-Help: List-Post: List-Id: "Log4J Developers List" Reply-To: "Log4J Developers List" Delivered-To: mailing list log4j-dev@logging.apache.org Received: (qmail 48250 invoked by uid 99); 8 Apr 2016 04:50:25 -0000 Received: from arcas.apache.org (HELO arcas) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 08 Apr 2016 04:50:25 +0000 Received: from arcas.apache.org (localhost [127.0.0.1]) by arcas (Postfix) with ESMTP id 7FEE32C1F4E for ; Fri, 8 Apr 2016 04:50:25 +0000 (UTC) Date: Fri, 8 Apr 2016 04:50:25 +0000 (UTC) From: "Remko Popma (JIRA)" To: log4j-dev@logging.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Comment Edited] (LOG4J2-1343) Update ConsoleAppender to utilize gc-free Layout method MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/LOG4J2-1343?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15231625#comment-15231625 ] Remko Popma edited comment on LOG4J2-1343 at 4/8/16 4:50 AM: ------------------------------------------------------------- The current implementation that coarsely locks on the Appender Manager causes a deadlock in {{org.apache.logging.log4j.core.ThreadedTest}}. The call sequence became clear after I added some system printouts: {noformat} pool-2-thread-1 ThreadedTest$LoggingRunnable@7df67951 calling logger.debug(state) pool-2-thread-2 ThreadedTest$StateSettingRunnable@20afdd66 locking on state to call state.setState pool-2-thread-2 ThreadedTest$State@7c7a06ec locked on state, entered setState, calling logger.debug... pool-2-thread-3 ThreadedTest$LoggingRunnable@215a8856 calling logger.debug(state) pool-2-thread-4 ThreadedTest$StateSettingRunnable@5f8707b5 locking on state to call state.setState pool-2-thread-5 ThreadedTest$LoggingRunnable@51b48833 calling logger.debug(state) pool-2-thread-6 ThreadedTest$StateSettingRunnable@2ba8331b locking on state to call state.setState pool-2-thread-7 ThreadedTest$LoggingRunnable@1a12ff63 calling logger.debug(state) pool-2-thread-8 ThreadedTest$StateSettingRunnable@452a6c88 locking on state to call state.setState pool-2-thread-7 File.directEncodeEvent() synchronizing on manager pool-2-thread-2 File.directEncodeEvent() synchronizing on manager pool-2-thread-5 File.directEncodeEvent() synchronizing on manager pool-2-thread-1 File.directEncodeEvent() synchronizing on manager pool-2-thread-3 File.directEncodeEvent() synchronizing on manager pool-2-thread-7 ThreadedTest$State@7c7a06ec locking on state to call state.getState (deadlock) {noformat} In the above example thread 2 has a lock on state, and tries to lock on manager (in {{logger.debug("hello")}}, while thread 7 is calling {{logger.debug(state)}}, has a lock on manager and tries to lock on state (from {{state.toString()}}. This means we cannot hold locks while turning the LogEvent into text. It is probably okay to hold a lock while turning that text into bytes though. was (Author: remkop@yahoo.com): The current implementation that coarsely locks on the Appender Manager causes a deadlock in {{org.apache.logging.log4j.core.ThreadedTest}}. The call sequence became clear after I added some system printouts: {noformat} pool-2-thread-1 ThreadedTest$LoggingRunnable@7df67951 calling logger.debug(state) pool-2-thread-2 ThreadedTest$StateSettingRunnable@20afdd66 locking on state to call state.setState pool-2-thread-2 ThreadedTest$State@7c7a06ec locked on state, entered setState, calling logger.debug... pool-2-thread-3 ThreadedTest$LoggingRunnable@215a8856 calling logger.debug(state) pool-2-thread-4 ThreadedTest$StateSettingRunnable@5f8707b5 locking on state to call state.setState pool-2-thread-5 ThreadedTest$LoggingRunnable@51b48833 calling logger.debug(state) pool-2-thread-6 ThreadedTest$StateSettingRunnable@2ba8331b locking on state to call state.setState pool-2-thread-7 ThreadedTest$LoggingRunnable@1a12ff63 calling logger.debug(state) pool-2-thread-8 ThreadedTest$StateSettingRunnable@452a6c88 locking on state to call state.setState pool-2-thread-7 File.directEncodeEvent() synchronizing on manager pool-2-thread-2 File.directEncodeEvent() synchronizing on manager pool-2-thread-5 File.directEncodeEvent() synchronizing on manager pool-2-thread-1 File.directEncodeEvent() synchronizing on manager pool-2-thread-3 File.directEncodeEvent() synchronizing on manager pool-2-thread-7 ThreadedTest$State@7c7a06ec locking on state to call state.getState (deadlock) {noformat} In the above example thread 2 has a lock on state, and tries to lock on manager (in {{logger.debug("hello")}}, while thread 7 is calling {{logger.debug(state)}}, has a lock on manager and tries to lock on state (from {{state.toString()}}. > Update ConsoleAppender to utilize gc-free Layout method > ------------------------------------------------------- > > Key: LOG4J2-1343 > URL: https://issues.apache.org/jira/browse/LOG4J2-1343 > Project: Log4j 2 > Issue Type: Improvement > Components: Appenders > Affects Versions: 2.5 > Reporter: Remko Popma > Assignee: Remko Popma > Fix For: 2.6 > > > TBD: would we want to include this in the upcoming 2.6 release? -- This message was sent by Atlassian JIRA (v6.3.4#6332) --------------------------------------------------------------------- To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org For additional commands, e-mail: log4j-dev-help@logging.apache.org