RE: Flink logging

[Oran Shuster]

It's hard for me to see the issue from what you posted, However i can post
how i added that jar to my flink pods and you can compare
Instead of creating a custom image i loaded the JAR as a config map

You can create a configMap easily from a file:
1.Download the jar you want
2.Create the configMap in k8s using this command kubectl create configmap
log4j-layout-template-json-2-16-0-jar
--from-file=log4j-layout-template-json-2.16.0.jar
3.Then in flink just mount the configMap and copy it to the lib folder with
the custom entrypoint

As for the logging config

rootLogger.level = INFO
rootLogger.appenderRef.console.ref = ConsoleAppender
rootLogger.appenderRef.rolling.ref = RollingFileAppender

logger.akka.name = akka
logger.akka.level = INFO
logger.kafka.name= org.apache.kafka
logger.kafka.level = INFO
logger.hadoop.name = org.apache.hadoop
logger.hadoop.level = INFO
logger.zookeeper.name = org.apache.zookeeper
logger.zookeeper.level = INFO
# Log all infos to the console
appender.console.name = ConsoleAppender
appender.console.type = CONSOLE
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %d{-MM-dd HH:mm:ss,SSS} %-5p %-60c %x
- %m%n
# Log all infos in the given rolling file
appender.rolling.name = RollingFileAppender
appender.rolling.type = RollingFile
appender.rolling.append = false
appender.rolling.fileName = ${sys:log.file}
appender.rolling.filePattern = ${sys:log.file}.%i
appender.rolling.layout.type = JsonTemplateLayout #This and all other
layout setting are the important part
appender.rolling.layout.compact = true
appender.rolling.layout.eventEol = true
appender.rolling.layout.stacktraceAsString = true
appender.rolling.policies.type = Policies
appender.rolling.policies.size.type = SizeBasedTriggeringPolicy
appender.rolling.policies.size.size=100MB
appender.rolling.strategy.type = DefaultRolloverStrategy
appender.rolling.strategy.max = 10
# Suppress the irrelevant (wrong) warnings from the Netty channel handler
logger.netty.name =
org.apache.flink.shaded.akka.org.jboss.netty.channel.DefaultChannelPipeline
logger.netty.level = OFF


On 2022/01/20 14:24:32 Jessy Ping wrote:
> Hi Team,
>
> How can I use log4j-layout-template-json in flink for logging in json
> format ?.
> I have tried to add this jar into the /flink/lib/ directory with a custom
> image and I am getting the following error.
> Any insight would be appreciated.
>
> [image: image.png]
>
> Thanks
> Jessy
>

Re: Flink Logging on EMR

[Arvid Heise]

Hi KristoffSC,

taskmanager.out should only show the output of the process starting the
taskmanager. In most cases, you probably want to look into taskmanager.log.

On Tue, Dec 29, 2020 at 3:42 PM KristoffSC 
wrote:

> Hi Mars,
> Were you able to solve this problem?
>
> I'm facing exact same issue. I dont see logs from taskmanager from my
> operators (taskmnager.out file) on EMR although running this locally from
> IDE logs are printed.
>
>
>
> --
> Sent from:
> http://apache-flink-user-mailing-list-archive.2336050.n4.nabble.com/
>


-- 

Arvid Heise | Senior Java Developer



Follow us @VervericaData

--

Join Flink Forward  - The Apache Flink
Conference

Stream Processing | Event Driven | Real Time

--

Ververica GmbH | Invalidenstrasse 115, 10115 Berlin, Germany

--
Ververica GmbH
Registered at Amtsgericht Charlottenburg: HRB 158244 B
Managing Directors: Timothy Alexander Steinert, Yip Park Tung Jason, Ji
(Toni) Cheng

Re: Flink Logging on EMR

[KristoffSC]

Hi Mars,
Were you able to solve this problem?

I'm facing exact same issue. I dont see logs from taskmanager from my
operators (taskmnager.out file) on EMR although running this locally from
IDE logs are printed. 



--
Sent from: http://apache-flink-user-mailing-list-archive.2336050.n4.nabble.com/

Re: Flink Logging on EMR

[Ken Krugler]

Hi Sateesh,

Note that there are three classes of log files, when running Flink on EMR:

1. The output from the main class.

Since I typically run the job by sshing onto the master and using the CLI from 
there, I have control over where that output goes. E.g.

nohup bin/flink run -m yarn-cluster -yn 48 /path/to/my-job.jar >> my.log 2>&1 &

And then:

tail -f my.log

2. Logging by the JobManager

The JobManager log is available via the Yarn Application Overview screen (see 
the Logs link in the attempt list near the bottom). When your tool fails (e.g., 
due to a missing command-line argument), the error output is available via the 
stderr link in that Step of the EMR Cluster > Steps tab

3. Logging by each TaskManager

I typically log into the slave to have a look at the Task Manager error/status 
output (e.g., in 
/var/log/hadoop-yarn/containers/application_1546471484145_0002/container_1546471484145_0002_01_02/taskmanager.err).
 One common approach here is to grep the taskmanager.log files (on each slave), 
e.g.

sudo find /var/log/hadoop-yarn/containers/application_1568579660214_0004/ -name 
"taskmanager.log" | sudo xargs grep “text of interest”

HTH,

— Ken
 
> On Jul 2, 2020, at 9:29 AM, mars  wrote:
> 
> Hi,
> 
>  I am running my Flink jobs on EMR and i didn't include any
> log4j.properties as part of my JAR and i am using slf4j (and included the
> dependent jars in the uber jar i created) and logging in my app.
> 
>  When i run my everything is running fine except i cannot find my
> application logs any where 
> 
> I am running the Flink job/app with (-p 2) i see two task managers and when
> i looked into the logs (none of the app specific logs can be found in those
> logs). We are using the INFO Level logging. 
> 
> I was hoping the logs will go to default Console Appender.
> 
> In the Master node Flink Conf i have found logback-console.xml (which sets
> the root level logging to INFO) and is using Console Appender and there is
> also log4j.properties file which also sets the Root Level logging to INFO
> and is using FileAppender
> 
> I also tried to access the logs using "yarn logs --applicationId <>" i am
> getting
> 
> $ yarn logs -applicationId application_1593579475717_0001
> 20/07/01 21:16:32 INFO client.RMProxy: Connecting to ResourceManager at
> <>:8032
> /var/log/hadoop-yarn/apps/root/logs/application_1593579475717_0001 does not
> exist.
> Log aggregation has not completed or is not enabled.
> 
> And Yarn Log Aggregation is already enabled. When i checked
> /etc/hadoop/conf/yarn-site.xml
> 
> 
>yarn.log-aggregation-enable
>true
> 
> 
> It might be the case that i can only see the logs through yarn once the
> application completes/finishes/fails
> 
> Thanks
> Sateesh
> 
> 
> 
> --
> Sent from: 
> http://apache-flink-user-mailing-list-archive.2336050.n4.nabble.com/

--
Ken Krugler
http://www.scaleunlimited.com
custom big data solutions & training
Hadoop, Cascading, Cassandra & Solr

Re: Flink logging issue with logback

[Maximilian Michels]

FYI, there is also a PR: https://github.com/apache/flink/pull/10811

On 09.01.20 01:53, Bajaj, Abhinav wrote:

Thanks Dawid, Max and Yang for confirming the issue and providing potential 
workaround.

On 1/8/20, 3:24 AM, "Maximilian Michels"  wrote:

 Interesting that we came across this problem at the same time. We have
 observed this with Lyft's K8s operator which uses the Rest API for job
 submission, much like the Flink dashboard.
 
 Note that you can restore the original stdout/stderr in your program:
 
private static void restoreStdOutAndStdErr() {

  System.setOut(new PrintStream(
  new FileOutputStream(FileDescriptor.out)));
  System.setErr(new PrintStream(
  new FileOutputStream(FileDescriptor.err)));
}
 
 Just call restoreStdOutAndStdErr() before you start building the Flink

 job. Of course, this is just meant to be a workaround.
 
 I think an acceptable solution is to always print upon execution. For

 the plan preview we may keep the existing behavior.
 
 Cheers,

 Max
 
 On 07.01.20 17:39, Dawid Wysakowicz wrote:

 > A quick update. The suppression of stdout/stderr actually might soon be
 > dropped, see: 
https://eur02.safelinks.protection.outlook.com/?url=https%3A%2F%2Fissues.apache.org%2Fjira%2Fbrowse%2FFLINK-15504data=01%7C01%7C%7Ce78cef8e4589a72d08d7942d53eb%7C6d4034cd72254f72b85391feaea64919%7C1sdata=a2dpid%2Fm1SN8%2F5sx09%2FbuVuk%2FI7UM%2BWMZtNALaYf8rU%3Dreserved=0
 >
 > Best,
 >
 > Dawid
 >
 > On 07/01/2020 07:17, Yang Wang wrote:
 >> Hi Bajaj,
 >>
 >> I have tested just as you say, and find that the logs in the user
 >> class could not show up when
 >> using ConsoleAppender. If using FileAppender instead, everything goes
 >> well.
 >>
 >> It is so weird and i have no idea how to debug it.
 >> Best,
 >> Yang
 >>
 >> Bajaj, Abhinav > <mailto:abhinav.ba...@here.com>> 于2020年1月7日周二 上午4:28写道：
 >>
 >> Hi,
 >>
 >> Thanks much for the responses.
 >>
 >> Let me add some more details and clarify my question.
 >>
 >> _Setup_
 >>
 >>   * I used the WikipediaAnalysis example and added a log in main
 >> method.
 >>
 >> ……
 >>
 >> public static void main(String[] args) throws Exception {
 >>   StreamExecutionEnvironment see =
 >> StreamExecutionEnvironment./getExecutionEnvironment/();
 >> /LOG/.info("Info log for test");
 >>
 >> DataStream edits = see.addSource(new
 >> WikipediaEditsSource());
 >>
 >> ……
 >>
 >>   * I am using the Flink 1.7.1 distribution and starting
 >> jobmanager and taskmanager locally using the below commands –
 >>   o ./bin/jobmanager.sh start-foreground
 >>   o ./bin/taskmanager.sh start-foreground
 >>   o Both jobmanager and taskmanager log in the console now
 >>   o JVM options are correctly set and verified from jobmanager
 >> & taskmanager logs
 >>
 >>   * I submit the WikipediaAnalysis job from Flink dashboard and
 >> checked the jobmanager logs
 >>
 >> _Run 1_: Flink is using the default log4j logging
 >>
 >>   * Jobmanager logs the added info log from the job
 >>   o 2020-01-06 11:55:37,422 INFO wikiedits.WikipediaAnalysis -
 >> Info log for test
 >>
 >> _Run 2_: Flink is setup to use logback as suggested in Flink
 >> documentation here
 >> 
<https://eur02.safelinks.protection.outlook.com/?url=https%3A%2F%2Fci.apache.org%2Fprojects%2Fflink%2Fflink-docs-stable%2Fdev%2Fbest_practices.html%23use-logback-when-running-flink-on-a-clusterdata=01%7C01%7C%7Ce78cef8e4589a72d08d7942d53eb%7C6d4034cd72254f72b85391feaea64919%7C1sdata=3heaNcREFAruHxyXCUjrySVKw14LIrHE8RKWV7gOpZU%3Dreserved=0>
 >>
 >>   * Jobmanger does not log the added info log from the job
 >>
 >> So, it seems there is a logging behavior difference between using
 >> log4j & logback in Flink.
 >>
 >> Is this expected or a known difference?
 >>
 >> Thanks again,
 >>
 >> Abhinav Bajaj
     >>
 >> _PS_: Ahh. I see how my email was confusing the first time.
 >> Hopefully this one is better :P
  

Re: Flink logging issue with logback

[Bajaj, Abhinav]

Thanks Dawid, Max and Yang for confirming the issue and providing potential 
workaround.

On 1/8/20, 3:24 AM, "Maximilian Michels"  wrote:

Interesting that we came across this problem at the same time. We have 
observed this with Lyft's K8s operator which uses the Rest API for job 
submission, much like the Flink dashboard.

Note that you can restore the original stdout/stderr in your program:

   private static void restoreStdOutAndStdErr() {
 System.setOut(new PrintStream(
 new FileOutputStream(FileDescriptor.out)));
 System.setErr(new PrintStream(
 new FileOutputStream(FileDescriptor.err)));
   }

Just call restoreStdOutAndStdErr() before you start building the Flink 
job. Of course, this is just meant to be a workaround.

I think an acceptable solution is to always print upon execution. For 
the plan preview we may keep the existing behavior.

Cheers,
Max

On 07.01.20 17:39, Dawid Wysakowicz wrote:
> A quick update. The suppression of stdout/stderr actually might soon be 
> dropped, see: 
https://eur02.safelinks.protection.outlook.com/?url=https%3A%2F%2Fissues.apache.org%2Fjira%2Fbrowse%2FFLINK-15504data=01%7C01%7C%7Ce78cef8e4589a72d08d7942d53eb%7C6d4034cd72254f72b85391feaea64919%7C1sdata=a2dpid%2Fm1SN8%2F5sx09%2FbuVuk%2FI7UM%2BWMZtNALaYf8rU%3Dreserved=0
> 
> Best,
> 
> Dawid
> 
> On 07/01/2020 07:17, Yang Wang wrote:
>> Hi Bajaj,
>>
>> I have tested just as you say, and find that the logs in the user 
>> class could not show up when
>> using ConsoleAppender. If using FileAppender instead, everything goes 
>> well.
>>
>> It is so weird and i have no idea how to debug it.
>> Best,
>> Yang
>>
>> Bajaj, Abhinav > <mailto:abhinav.ba...@here.com>> 于2020年1月7日周二 上午4:28写道：
>>
>> Hi,
>>
>> Thanks much for the responses.
>>
>> Let me add some more details and clarify my question.
>>
>> _Setup_
>>
>>   * I used the WikipediaAnalysis example and added a log in main
>> method.
>>
>> ……
>>
>> public static void main(String[] args) throws Exception {
>>   StreamExecutionEnvironment see =
>> StreamExecutionEnvironment./getExecutionEnvironment/();
>> /LOG/.info("Info log for test");
>>
>> DataStream edits = see.addSource(new
>> WikipediaEditsSource());
>>
>> ……
>>
>>   * I am using the Flink 1.7.1 distribution and starting
>> jobmanager and taskmanager locally using the below commands –
>>   o ./bin/jobmanager.sh start-foreground
>>   o ./bin/taskmanager.sh start-foreground
>>   o Both jobmanager and taskmanager log in the console now
>>   o JVM options are correctly set and verified from jobmanager
>> & taskmanager logs
>>
>>   * I submit the WikipediaAnalysis job from Flink dashboard and
>> checked the jobmanager logs
>>
>> _Run 1_: Flink is using the default log4j logging
>>
>>   * Jobmanager logs the added info log from the job
>>   o 2020-01-06 11:55:37,422 INFO wikiedits.WikipediaAnalysis -
>> Info log for test
>>
>> _Run 2_: Flink is setup to use logback as suggested in Flink
>> documentation here
>> 
<https://eur02.safelinks.protection.outlook.com/?url=https%3A%2F%2Fci.apache.org%2Fprojects%2Fflink%2Fflink-docs-stable%2Fdev%2Fbest_practices.html%23use-logback-when-running-flink-on-a-clusterdata=01%7C01%7C%7Ce78cef8e4589a72d08d7942d53eb%7C6d4034cd72254f72b85391feaea64919%7C1sdata=3heaNcREFAruHxyXCUjrySVKw14LIrHE8RKWV7gOpZU%3Dreserved=0>
>>
>>   * Jobmanger does not log the added info log from the job
>>
>> So, it seems there is a logging behavior difference between using
>> log4j & logback in Flink.
>>
>> Is this expected or a known difference?
>>
>> Thanks again,
>>
>> Abhinav Bajaj
    >>
>> _PS_: Ahh. I see how my email was confusing the first time.
>> Hopefully this one is better :P
>>
>> *From: *Dawid Wysakowicz > <mailto:dwysakow...@apache.org>>
>> *Date: *Monday, January 6, 2020 at 5:13 AM
>> *Cc: *"Bajaj, Abhinav" >   

Re: Flink logging issue with logback

[Maximilian Michels]

Interesting that we came across this problem at the same time. We have 
observed this with Lyft's K8s operator which uses the Rest API for job 
submission, much like the Flink dashboard.


Note that you can restore the original stdout/stderr in your program:

  private static void restoreStdOutAndStdErr() {
System.setOut(new PrintStream(
new FileOutputStream(FileDescriptor.out)));
System.setErr(new PrintStream(
new FileOutputStream(FileDescriptor.err)));
  }

Just call restoreStdOutAndStdErr() before you start building the Flink 
job. Of course, this is just meant to be a workaround.


I think an acceptable solution is to always print upon execution. For 
the plan preview we may keep the existing behavior.


Cheers,
Max

On 07.01.20 17:39, Dawid Wysakowicz wrote:
A quick update. The suppression of stdout/stderr actually might soon be 
dropped, see: https://issues.apache.org/jira/browse/FLINK-15504


Best,

Dawid

On 07/01/2020 07:17, Yang Wang wrote:

Hi Bajaj,

I have tested just as you say, and find that the logs in the user 
class could not show up when
using ConsoleAppender. If using FileAppender instead, everything goes 
well.


It is so weird and i have no idea how to debug it.
Best,
Yang

Bajaj, Abhinav <mailto:abhinav.ba...@here.com>> 于2020年1月7日周二 上午4:28写道：


Hi,

Thanks much for the responses.

Let me add some more details and clarify my question.

_Setup_

  * I used the WikipediaAnalysis example and added a log in main
method.

……

public static void main(String[] args) throws Exception {
  StreamExecutionEnvironment see =
StreamExecutionEnvironment./getExecutionEnvironment/();
/LOG/.info("Info log for test");

DataStream edits = see.addSource(new
WikipediaEditsSource());

……

  * I am using the Flink 1.7.1 distribution and starting
jobmanager and taskmanager locally using the below commands –
  o ./bin/jobmanager.sh start-foreground
  o ./bin/taskmanager.sh start-foreground
  o Both jobmanager and taskmanager log in the console now
  o JVM options are correctly set and verified from jobmanager
& taskmanager logs

  * I submit the WikipediaAnalysis job from Flink dashboard and
checked the jobmanager logs

_Run 1_: Flink is using the default log4j logging

  * Jobmanager logs the added info log from the job
  o 2020-01-06 11:55:37,422 INFO wikiedits.WikipediaAnalysis -
Info log for test

_Run 2_: Flink is setup to use logback as suggested in Flink
documentation here

<https://ci.apache.org/projects/flink/flink-docs-stable/dev/best_practices.html#use-logback-when-running-flink-on-a-cluster>

  * Jobmanger does not log the added info log from the job

So, it seems there is a logging behavior difference between using
log4j & logback in Flink.

Is this expected or a known difference?

Thanks again,

Abhinav Bajaj

_PS_: Ahh. I see how my email was confusing the first time.
Hopefully this one is better :P

*From: *Dawid Wysakowicz mailto:dwysakow...@apache.org>>
*Date: *Monday, January 6, 2020 at 5:13 AM
*Cc: *"Bajaj, Abhinav" mailto:abhinav.ba...@here.com>>, "user@flink.apache.org
<mailto:user@flink.apache.org>" mailto:user@flink.apache.org>>
*Subject: *Re: Flink logging issue with logback

Hi Bajaj,

I am not entirely sure what is the actual issue you are seeking
help, but let me comment on your observations.

Ad. 1

If you log to the console from the main method this is an expected
behavior in both cases (log4j, logback). The std out is being
overwritten for the execution of the main method

If you log to a file logs should work in both cases. I checked
that myself and actually the logs appeared in the jobmanager logs
as long as they are executed before the env.execute(). I observed
though weird behavior of the Web UI, as it does not always update
the logs that are displayed. How did you check the logs? If you
checked through the Web UI could you try to check the file directly?

Ad. 2 Yes this is expected. Operators are executed on taskmanager
and that's why they log there.

Ad. 3 See Ad. 1

Best,

Dawid

On 06/01/2020 07:07, vino yang wrote:

Hi Bajaj,

>> Logs from main method(outside of job graph) do not show up
in jobmanager logs.

IMO, it's normal phenomena.

Other ideas, please check the JVM options mentioned by Yang.

Best,

Vino

Yang Wang mailto:danrtsey...@gmail.com>> 于2020年1月6日周一 上午11:18写道：

Hi Bajaj, Abhinav,

Could you share the start-command of jobmanager and
taskmanager. If it is started correctly, we

will have a the following jvm options.

-Dlog.file=/pa

Re: Flink logging issue with logback

[Dawid Wysakowicz]

A quick update. The suppression of stdout/stderr actually might soon be
dropped, see: https://issues.apache.org/jira/browse/FLINK-15504

Best,

Dawid

On 07/01/2020 07:17, Yang Wang wrote:
> Hi Bajaj,
>
> I have tested just as you say, and find that the logs in the user
> class could not show up when
> using ConsoleAppender. If using FileAppender instead, everything goes
> well. 
>
> It is so weird and i have no idea how to debug it.
> Best,
> Yang
>
> Bajaj, Abhinav  <mailto:abhinav.ba...@here.com>> 于2020年1月7日周二 上午4:28写道：
>
> Hi,
>
>  
>
> Thanks much for the responses.
>
> Let me add some more details and clarify my question.
>
>  
>
> _Setup_
>
>   * I used the WikipediaAnalysis example and added a log in main
> method.
>
> ……
>
> public static void main(String[] args) throws Exception {
>   StreamExecutionEnvironment see =
> StreamExecutionEnvironment./getExecutionEnvironment/();
>   /LOG/.info("Info log for test");
>
>   DataStream edits = see.addSource(new
> WikipediaEditsSource());
>
> ……
>
>   * I am using the Flink 1.7.1 distribution and starting
> jobmanager and taskmanager locally using the below commands –
>   o ./bin/jobmanager.sh start-foreground
>   o ./bin/taskmanager.sh start-foreground
>   o Both jobmanager and taskmanager log in the console now
>   o JVM options are correctly set and verified from jobmanager
> & taskmanager logs
>
>  
>
>   * I submit the WikipediaAnalysis job from Flink dashboard and
> checked the jobmanager logs
>
>  
>
> _Run 1_: Flink is using the default log4j logging
>
>   * Jobmanager logs the added info log from the job
>   o 2020-01-06 11:55:37,422 INFO 
> wikiedits.WikipediaAnalysis  
> - Info log for test
>
>  
>
> _Run 2_: Flink is setup to use logback as suggested in Flink
> documentation here
> 
> <https://ci.apache.org/projects/flink/flink-docs-stable/dev/best_practices.html#use-logback-when-running-flink-on-a-cluster>
>
>   * Jobmanger does not log the added info log from the job
>
>  
>
> So, it seems there is a logging behavior difference between using
> log4j & logback in Flink.
>
> Is this expected or a known difference?
>
>  
>
> Thanks again,
>
> Abhinav Bajaj
>
>  
>
>  
>
> _PS_: Ahh. I see how my email was confusing the first time.
> Hopefully this one is better :P
>
>  
>
>  
>
> *From: *Dawid Wysakowicz  <mailto:dwysakow...@apache.org>>
> *Date: *Monday, January 6, 2020 at 5:13 AM
> *Cc: *"Bajaj, Abhinav"  <mailto:abhinav.ba...@here.com>>, "user@flink.apache.org
> <mailto:user@flink.apache.org>"  <mailto:user@flink.apache.org>>
> *Subject: *Re: Flink logging issue with logback
>
>  
>
> Hi Bajaj,
>
> I am not entirely sure what is the actual issue you are seeking
> help, but let me comment on your observations.
>
> Ad. 1
>
> If you log to the console from the main method this is an expected
> behavior in both cases (log4j, logback). The std out is being
> overwritten for the execution of the main method
>
> If you log to a file logs should work in both cases. I checked
> that myself and actually the logs appeared in the jobmanager logs
> as long as they are executed before the env.execute(). I observed
> though weird behavior of the Web UI, as it does not always update
> the logs that are displayed. How did you check the logs? If you
> checked through the Web UI could you try to check the file directly?
>
> Ad. 2 Yes this is expected. Operators are executed on taskmanager
> and that's why they log there.
>
> Ad. 3 See Ad. 1
>
> Best,
>
> Dawid
>
>  
>
> On 06/01/2020 07:07, vino yang wrote:
>
> Hi Bajaj,
>
>  
>
> >> Logs from main method(outside of job graph) do not show up
> in jobmanager logs.
>
>  
>
> IMO, it's normal phenomena.
>
>  
>
> Other ideas, please check the JVM options mentioned by Yang.
>
>  
>
> Best,
>
> Vino
>
>  
>
>  
>
> Yang Wang  <mailto:danrtsey...@gmail.com>> 于2020年1月6日周一 上午11:18写道：
>
> Hi Bajaj, Abhinav,
>

Re: Flink logging issue with logback

[Dawid Wysakowicz]

Hi Bajaj,

I spent a bit more time on that and I figured out the difference. The
cause is in the implementation of log4j's ConsoleAppender.

So first of all as I said before, the code path that submits a job
through Web UI redirects the std.out and std.err to a memory buffer for
the time of the "main" method execution. This is the expected behavior.
That's why the logback does not log anything. Log4j implementation is
slightly different as by default it does not follow changes to the
System#setOut. It buffers the original System.out. It has an option
though to also follow changes to the System.out: ConsoleAppender#follow
(https://logging.apache.org/log4j/2.x/manual/appenders.html). If enabled
the log4j behaves exactly the same way as logback. After a very brief
check I could not find such property for logback (actually I like
logback's approach better).

Hope it clarifies the difference.

Best,

Dawid

On 07/01/2020 07:17, Yang Wang wrote:
> Hi Bajaj,
>
> I have tested just as you say, and find that the logs in the user
> class could not show up when
> using ConsoleAppender. If using FileAppender instead, everything goes
> well. 
>
> It is so weird and i have no idea how to debug it.
> Best,
> Yang
>
> Bajaj, Abhinav  <mailto:abhinav.ba...@here.com>> 于2020年1月7日周二 上午4:28写道：
>
> Hi,
>
>  
>
> Thanks much for the responses.
>
> Let me add some more details and clarify my question.
>
>  
>
> _Setup_
>
>   * I used the WikipediaAnalysis example and added a log in main
> method.
>
> ……
>
> public static void main(String[] args) throws Exception {
>   StreamExecutionEnvironment see =
> StreamExecutionEnvironment./getExecutionEnvironment/();
>   /LOG/.info("Info log for test");
>
>   DataStream edits = see.addSource(new
> WikipediaEditsSource());
>
> ……
>
>   * I am using the Flink 1.7.1 distribution and starting
> jobmanager and taskmanager locally using the below commands –
>   o ./bin/jobmanager.sh start-foreground
>   o ./bin/taskmanager.sh start-foreground
>   o Both jobmanager and taskmanager log in the console now
>   o JVM options are correctly set and verified from jobmanager
> & taskmanager logs
>
>  
>
>   * I submit the WikipediaAnalysis job from Flink dashboard and
> checked the jobmanager logs
>
>  
>
> _Run 1_: Flink is using the default log4j logging
>
>   * Jobmanager logs the added info log from the job
>   o 2020-01-06 11:55:37,422 INFO 
> wikiedits.WikipediaAnalysis  
> - Info log for test
>
>  
>
> _Run 2_: Flink is setup to use logback as suggested in Flink
> documentation here
> 
> <https://ci.apache.org/projects/flink/flink-docs-stable/dev/best_practices.html#use-logback-when-running-flink-on-a-cluster>
>
>   * Jobmanger does not log the added info log from the job
>
>  
>
> So, it seems there is a logging behavior difference between using
> log4j & logback in Flink.
>
> Is this expected or a known difference?
>
>  
>
> Thanks again,
>
> Abhinav Bajaj
>
>  
>
>  
>
> _PS_: Ahh. I see how my email was confusing the first time.
> Hopefully this one is better :P
>
>      
>
>      
>
> *From: *Dawid Wysakowicz  <mailto:dwysakow...@apache.org>>
> *Date: *Monday, January 6, 2020 at 5:13 AM
> *Cc: *"Bajaj, Abhinav"  <mailto:abhinav.ba...@here.com>>, "user@flink.apache.org
> <mailto:user@flink.apache.org>"  <mailto:user@flink.apache.org>>
> *Subject: *Re: Flink logging issue with logback
>
>  
>
> Hi Bajaj,
>
> I am not entirely sure what is the actual issue you are seeking
> help, but let me comment on your observations.
>
> Ad. 1
>
> If you log to the console from the main method this is an expected
> behavior in both cases (log4j, logback). The std out is being
> overwritten for the execution of the main method
>
> If you log to a file logs should work in both cases. I checked
> that myself and actually the logs appeared in the jobmanager logs
> as long as they are executed before the env.execute(). I observed
> though weird behavior of the Web UI, as it does not always update
> the logs that are displayed. How did you check the logs? If you
> checked through the Web UI could you try to check the file directly?
>
> Ad. 2 Yes this is expected. Operators are executed on taskma

Re: Flink logging issue with logback

[Yang Wang]

Hi Bajaj,

I have tested just as you say, and find that the logs in the user class
could not show up when
using ConsoleAppender. If using FileAppender instead, everything goes well.

It is so weird and i have no idea how to debug it.


Best,

Yang


Bajaj, Abhinav  于2020年1月7日周二 上午4:28写道：

> Hi,
>
>
>
> Thanks much for the responses.
>
> Let me add some more details and clarify my question.
>
>
>
> *Setup*
>
>- I used the WikipediaAnalysis example and added a log in main method.
>
> ……
>
> public static void main(String[] args) throws Exception {
>   StreamExecutionEnvironment see = StreamExecutionEnvironment.
> *getExecutionEnvironment*();
>   *LOG*.info("Info log for test");
>
>   DataStream edits = see.addSource(new
> WikipediaEditsSource());
>
> ……
>
>- I am using the Flink 1.7.1 distribution and starting jobmanager and
>taskmanager locally using the below commands –
>   - ./bin/jobmanager.sh start-foreground
>   - ./bin/taskmanager.sh start-foreground
>   - Both jobmanager and taskmanager log in the console now
>   - JVM options are correctly set and verified from jobmanager &
>   taskmanager logs
>
>
>
>- I submit the WikipediaAnalysis job from Flink dashboard and checked
>the jobmanager logs
>
>
>
> *Run 1*: Flink is using the default log4j logging
>
>- Jobmanager logs the added info log from the job
>   - 2020-01-06 11:55:37,422 INFO
>   wikiedits.WikipediaAnalysis   - Info log
>   for test
>
>
>
> *Run 2*: Flink is setup to use logback as suggested in Flink
> documentation here
> <https://ci.apache.org/projects/flink/flink-docs-stable/dev/best_practices.html#use-logback-when-running-flink-on-a-cluster>
>
>- Jobmanger does not log the added info log from the job
>
>
>
> So, it seems there is a logging behavior difference between using log4j &
> logback in Flink.
>
> Is this expected or a known difference?
>
>
>
> Thanks again,
>
> Abhinav Bajaj
>
>
>
>
>
> *PS*: Ahh. I see how my email was confusing the first time. Hopefully
> this one is better :P
>
>
>
>
>
> *From: *Dawid Wysakowicz 
> *Date: *Monday, January 6, 2020 at 5:13 AM
> *Cc: *"Bajaj, Abhinav" , "user@flink.apache.org" <
> user@flink.apache.org>
> *Subject: *Re: Flink logging issue with logback
>
>
>
> Hi Bajaj,
>
> I am not entirely sure what is the actual issue you are seeking help, but
> let me comment on your observations.
>
> Ad. 1
>
> If you log to the console from the main method this is an expected
> behavior in both cases (log4j, logback). The std out is being overwritten
> for the execution of the main method
>
> If you log to a file logs should work in both cases. I checked that myself
> and actually the logs appeared in the jobmanager logs as long as they are
> executed before the env.execute(). I observed though weird behavior of the
> Web UI, as it does not always update the logs that are displayed. How did
> you check the logs? If you checked through the Web UI could you try to
> check the file directly?
>
> Ad. 2 Yes this is expected. Operators are executed on taskmanager and
> that's why they log there.
>
> Ad. 3 See Ad. 1
>
> Best,
>
> Dawid
>
>
>
> On 06/01/2020 07:07, vino yang wrote:
>
> Hi Bajaj,
>
>
>
> >> Logs from main method(outside of job graph) do not show up in
> jobmanager logs.
>
>
>
> IMO, it's normal phenomena.
>
>
>
> Other ideas, please check the JVM options mentioned by Yang.
>
>
>
> Best,
>
> Vino
>
>
>
>
>
> Yang Wang  于2020年1月6日周一 上午11:18写道：
>
> Hi Bajaj, Abhinav,
>
>
>
> Could you share the start-command of jobmanager and taskmanager. If it is
> started correctly, we
>
> will have a the following jvm options.
>
>
>
> -Dlog.file=/path/of/taskmanager.log -Dlogback.configurationFile=
> file:///path/of/logback.xml
>
>
>
>
>
>
>
> Best,
>
> Yang
>
>
>
> Bajaj, Abhinav  于2020年1月4日周六 上午7:23写道：
>
> Hi,
>
>
>
> I am investigating a logging issue with Flink.
>
>
>
> *Setup*
>
>- Using Flink-1.7.1 using logback as suggested in Flink documentation
>here
>
> <https://ci.apache.org/projects/flink/flink-docs-stable/dev/best_practices.html#use-logback-when-running-flink-on-a-cluster>
>.
>- Submitting the Flink job from the Flink dashboard.
>
>
>
> *Observations*
>
>- Logs from main method(outside of job graph) do not show up in
>jobmanager logs.
>- Logs from the operators like map or custom operators do show up in
>the taskmanager logs.
>- Logs from main method do show up in jobmanager logs when using log4j
>in place of logback.
>
>
>
> Has anyone else noticed similar behavior or is this a known issue with
> logback integration in Flink?
>
> Any suggestions on potential workaround or fix?
>
>
>
> Appreciate your time and help.
>
>
>
> ~ Abhinav Bajaj
>
>
>
>

Re: Flink logging issue with logback

[Bajaj, Abhinav]

Hi,

Thanks much for the responses.
Let me add some more details and clarify my question.

Setup

  *   I used the WikipediaAnalysis example and added a log in main method.
……
public static void main(String[] args) throws Exception {
  StreamExecutionEnvironment see = 
StreamExecutionEnvironment.getExecutionEnvironment();
  LOG.info("Info log for test");
  DataStream edits = see.addSource(new 
WikipediaEditsSource());
……

  *   I am using the Flink 1.7.1 distribution and starting jobmanager and 
taskmanager locally using the below commands –
 *   ./bin/jobmanager.sh start-foreground
 *   ./bin/taskmanager.sh start-foreground
 *   Both jobmanager and taskmanager log in the console now
 *   JVM options are correctly set and verified from jobmanager & 
taskmanager logs



  *   I submit the WikipediaAnalysis job from Flink dashboard and checked the 
jobmanager logs

Run 1: Flink is using the default log4j logging

  *   Jobmanager logs the added info log from the job
 *   2020-01-06 11:55:37,422 INFO  wikiedits.WikipediaAnalysis  
 - Info log for test

Run 2: Flink is setup to use logback as suggested in Flink documentation 
here<https://ci.apache.org/projects/flink/flink-docs-stable/dev/best_practices.html#use-logback-when-running-flink-on-a-cluster>

  *   Jobmanger does not log the added info log from the job

So, it seems there is a logging behavior difference between using log4j & 
logback in Flink.
Is this expected or a known difference?

Thanks again,
Abhinav Bajaj


PS: Ahh. I see how my email was confusing the first time. Hopefully this one is 
better :P


From: Dawid Wysakowicz 
Date: Monday, January 6, 2020 at 5:13 AM
Cc: "Bajaj, Abhinav" , "user@flink.apache.org" 

Subject: Re: Flink logging issue with logback


Hi Bajaj,

I am not entirely sure what is the actual issue you are seeking help, but let 
me comment on your observations.

Ad. 1

If you log to the console from the main method this is an expected behavior in 
both cases (log4j, logback). The std out is being overwritten for the execution 
of the main method

If you log to a file logs should work in both cases. I checked that myself and 
actually the logs appeared in the jobmanager logs as long as they are executed 
before the env.execute(). I observed though weird behavior of the Web UI, as it 
does not always update the logs that are displayed. How did you check the logs? 
If you checked through the Web UI could you try to check the file directly?

Ad. 2 Yes this is expected. Operators are executed on taskmanager and that's 
why they log there.

Ad. 3 See Ad. 1

Best,

Dawid


On 06/01/2020 07:07, vino yang wrote:
Hi Bajaj,

>> Logs from main method(outside of job graph) do not show up in jobmanager 
>> logs.

IMO, it's normal phenomena.

Other ideas, please check the JVM options mentioned by Yang.

Best,
Vino


Yang Wang mailto:danrtsey...@gmail.com>> 于2020年1月6日周一 
上午11:18写道：
Hi Bajaj, Abhinav,

Could you share the start-command of jobmanager and taskmanager. If it is 
started correctly, we
will have a the following jvm options.

-Dlog.file=/path/of/taskmanager.log 
-Dlogback.configurationFile=file:///path/of/logback.xml



Best,
Yang

Bajaj, Abhinav mailto:abhinav.ba...@here.com>> 
于2020年1月4日周六 上午7:23写道：
Hi,

I am investigating a logging issue with Flink.

Setup

  *   Using Flink-1.7.1 using logback as suggested in Flink documentation 
here<https://ci.apache.org/projects/flink/flink-docs-stable/dev/best_practices.html#use-logback-when-running-flink-on-a-cluster>.
  *   Submitting the Flink job from the Flink dashboard.

Observations

  *   Logs from main method(outside of job graph) do not show up in jobmanager 
logs.
  *   Logs from the operators like map or custom operators do show up in the 
taskmanager logs.
  *   Logs from main method do show up in jobmanager logs when using log4j in 
place of logback.

Has anyone else noticed similar behavior or is this a known issue with logback 
integration in Flink?
Any suggestions on potential workaround or fix?

Appreciate your time and help.

~ Abhinav Bajaj

Re: Flink logging issue with logback

[Dawid Wysakowicz]

Hi Bajaj,

I am not entirely sure what is the actual issue you are seeking help,
but let me comment on your observations.

Ad. 1

If you log to the console from the main method this is an expected
behavior in both cases (log4j, logback). The std out is being
overwritten for the execution of the main method

If you log to a file logs should work in both cases. I checked that
myself and actually the logs appeared in the jobmanager logs as long as
they are executed before the env.execute(). I observed though weird
behavior of the Web UI, as it does not always update the logs that are
displayed. How did you check the logs? If you checked through the Web UI
could you try to check the file directly?

Ad. 2 Yes this is expected. Operators are executed on taskmanager and
that's why they log there.

Ad. 3 See Ad. 1

Best,

Dawid


On 06/01/2020 07:07, vino yang wrote:
> Hi Bajaj,
>
> >> Logs from main method(outside of job graph) do not show up in
> jobmanager logs.
>
> IMO, it's normal phenomena.
>
> Other ideas, please check the JVM options mentioned by Yang.
>
> Best,
> Vino
>
>
> Yang Wang mailto:danrtsey...@gmail.com>>
> 于2020年1月6日周一 上午11:18写道：
>
> Hi Bajaj, Abhinav,
>
> Could you share the start-command of jobmanager and taskmanager.
> If it is started correctly, we
> will have a the following jvm options.
>
> -Dlog.file=/path/of/taskmanager.log
> -Dlogback.configurationFile=file:///path/of/logback.xml
>
>
>
> Best,
> Yang
>
> Bajaj, Abhinav  > 于2020年1月4日周六 上午7:23写道：
>
> Hi,
>
>  
>
> I am investigating a logging issue with Flink.
>
>  
>
> _Setup_
>
>   * Using Flink-1.7.1 using logback as suggested in Flink
> documentation here
> 
> .
>   * Submitting the Flink job from the Flink dashboard.
>
>  
>
> _Observations_
>
>   * Logs from main method(outside of job graph) do not show up
> in jobmanager logs.
>   * Logs from the operators like map or custom operators do
> show up in the taskmanager logs.
>   * Logs from main method do show up in jobmanager logs when
> using log4j in place of logback.
>
>  
>
> Has anyone else noticed similar behavior or is this a known
> issue with logback integration in Flink?
>
> Any suggestions on potential workaround or fix?
>
>  
>
> Appreciate your time and help.
>
>  
>
> ~ Abhinav Bajaj
>
>  
>


signature.asc
Description: OpenPGP digital signature

Re: Flink logging issue with logback

[vino yang]

Hi Bajaj,

>> Logs from main method(outside of job graph) do not show up in jobmanager
logs.

IMO, it's normal phenomena.

Other ideas, please check the JVM options mentioned by Yang.

Best,
Vino


Yang Wang  于2020年1月6日周一 上午11:18写道：

> Hi Bajaj, Abhinav,
>
> Could you share the start-command of jobmanager and taskmanager. If it is
> started correctly, we
> will have a the following jvm options.
>
> -Dlog.file=/path/of/taskmanager.log
> -Dlogback.configurationFile=file:///path/of/logback.xml
>
>
>
> Best,
> Yang
>
> Bajaj, Abhinav  于2020年1月4日周六 上午7:23写道：
>
>> Hi,
>>
>>
>>
>> I am investigating a logging issue with Flink.
>>
>>
>>
>> *Setup*
>>
>>- Using Flink-1.7.1 using logback as suggested in Flink documentation
>>here
>>
>> 
>>.
>>- Submitting the Flink job from the Flink dashboard.
>>
>>
>>
>> *Observations*
>>
>>- Logs from main method(outside of job graph) do not show up in
>>jobmanager logs.
>>- Logs from the operators like map or custom operators do show up in
>>the taskmanager logs.
>>- Logs from main method do show up in jobmanager logs when using
>>log4j in place of logback.
>>
>>
>>
>> Has anyone else noticed similar behavior or is this a known issue with
>> logback integration in Flink?
>>
>> Any suggestions on potential workaround or fix?
>>
>>
>>
>> Appreciate your time and help.
>>
>>
>>
>> ~ Abhinav Bajaj
>>
>>
>>
>

Re: Flink logging issue with logback

[Yang Wang]

Hi Bajaj, Abhinav,

Could you share the start-command of jobmanager and taskmanager. If it is
started correctly, we
will have a the following jvm options.

-Dlog.file=/path/of/taskmanager.log
-Dlogback.configurationFile=file:///path/of/logback.xml



Best,
Yang

Bajaj, Abhinav  于2020年1月4日周六 上午7:23写道：

> Hi,
>
>
>
> I am investigating a logging issue with Flink.
>
>
>
> *Setup*
>
>- Using Flink-1.7.1 using logback as suggested in Flink documentation
>here
>
> 
>.
>- Submitting the Flink job from the Flink dashboard.
>
>
>
> *Observations*
>
>- Logs from main method(outside of job graph) do not show up in
>jobmanager logs.
>- Logs from the operators like map or custom operators do show up in
>the taskmanager logs.
>- Logs from main method do show up in jobmanager logs when using log4j
>in place of logback.
>
>
>
> Has anyone else noticed similar behavior or is this a known issue with
> logback integration in Flink?
>
> Any suggestions on potential workaround or fix?
>
>
>
> Appreciate your time and help.
>
>
>
> ~ Abhinav Bajaj
>
>
>