You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@drill.apache.org by John Omernik <jo...@omernik.com> on 2015/10/08 19:09:36 UTC

Drill Logging

Hello all -

I am playing with Drill (I have 1.2 running right now) and I am trying to
figure out a way to do some logging in a logical way.  I know I am running
outside the norm, in that I am running my drill bits using marathon on
mesos, but for a moment (unless it's THAT that is breaking my logging :)
ignore that fact :)

I am using MapR, which is nice because it lets me NFS mount my distributed
file system (MapRFS) Thus, when I run a drillbit, I package up the
drill-1.2.0 directory (I am using the MapR packaged version) and then in
Marathon I create a app profile like this

{
"cmd": "./drill-1.2.0/bin/runbit --config
/mapr/zetapoc/mesos/prod/drill/conf.std",
"cpus": 12.0,
"mem": 22528,
"id": "zetadrill",
"instances": 5,
"uris":["hdfs:///mesos/prod/drill/drill-1.2.0.tgz"],
"constraints": [["hostname", "UNIQUE"]]
}

Pretty basic, for non Mesos folks, it takes the URI (the tgz) downloads it
to the Mesos Sandbox, untars it there, and runs 'runbit' using cgroups.
Thus the memory and cpu specifications.  I am passing it a full path to the
config location which is just the /conf  copied out of the drill-1.2.0
directory and modified. Thus, all bits are pulling from the same conf. (I
could package the conf in the tgz, this makes its easy to change a config
and not have to repackage the tgz)

Also, as you can see I am using the constraint to only have one per node,
this is handy from a port conflict point of view.

Ok, that out of the way, when I run it, in my drill-env.sh, I am setting:
export DRILL_LOG_DIR="./drill-1.2.0/log"

What I "think" that means is it should log inside the sandbox. And sure
enough, when I look in the sandbox in mesos, in the log directory, there is
a profiles folder and the sys.drill (query logs... I think?)

Great.

Now, in the stdout on each node that started drill, I do have the error
below... and additionally, I don't see the drillbit.log and drillbit.out
files.  (Is that because of the errors below?) Wouldn't these be in
./drill-1.2.0/log as well?

Side note: If I am doing a CTAS to Parquet, one of my nodes starts spitting
out INFO logs to the console like crazy during the write, not sure what
that is all about...

Ok, back to logging. I am trying to organize this, ideally, I want to
understand logging deeply to meet a number of requirements

1.  I'd like all profiles/sql audit logs logged to one place.  Ideally,
this would make it so if I click profiles on any node, I'd see the
historical queries for all nodes, not just the one I am connected to.  Is
this possible? Right now, I am only seeing the historical queries if I am
connected to a node that acted as foreman for that query

2.  I'd like to keep all my logs in MapRFS with NFS, thus I'd like all
nodes, for logfiles that have the same names (like drillbit.log and
drillbit.out) to write to a file in the same networked location, but have
the hostname in the logfile name.  This would allow me to log to the same
place on all nodes, but I'd need to know how to do the hostname thing (if
that is possible)

3. Are there any gotchas to what I am trying to do?  What about having more
control over pruning? i.e. Can I keep the sql audit logs in a directory,
and those will show up in the console, but have an job or setting (inside
or outside drill) to move them to a "final" resting place for longterm
auditing?

I know some of these things may be obvious to users of drill, I have been
having a hard time digging through the docs (for example, I am not sure
where to find a good explanation of ENV vars that may help me here), any
advice would be welcome!

John



Error on in STDOUT on sandbox.. is this hurting me?


16:35:22,996 |-INFO in
ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - Active log file
name:

16:35:22,996 |-INFO in
ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - File property is
set to []

16:35:22,998 |-ERROR in
ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - openFile(,true)
call failed. java.io.FileNotFoundException:  (No such file or directory)

        at java.io.FileNotFoundException:  (No such file or directory)

        at      at java.io.FileOutputStream.open(Native Method)

        at      at
java.io.FileOutputStream.<init>(FileOutputStream.java:221)

        at      at
ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:28)

        at      at
ch.qos.logback.core.FileAppender.openFile(FileAppender.java:149)

        at      at
ch.qos.logback.core.FileAppender.start(FileAppender.java:108)

        at      at
ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:86)

        at      at
ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)

        at      at
ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)

        at      at
ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)

        at      at
ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)

        at      at
ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)

        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)

        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)

        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)

        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)

        at      at
ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)

        at      at
ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)

        at      at
org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)

        at      at
org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)

        at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)

        at      at
org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)

        at      at
org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)

        at      at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)

        at      at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)

        at      at
org.apache.drill.exec.server.Drillbit.<clinit>(Drillbit.java:50)

16:35:22,998 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
About to instantiate appender of type
[ch.qos.logback.core.rolling.RollingFileAppender]

16:35:22,998 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
Naming appender as [FILE]

16:35:23,000 |-INFO in
ch.qos.logback.core.rolling.FixedWindowRollingPolicy@6982bec3 - No
compression will be used

16:35:23,001 |-INFO in
ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default
type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder]
property

16:35:23,002 |-INFO in
ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file
name:

16:35:23,002 |-INFO in
ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is
set to []

16:35:23,002 |-ERROR in
ch.qos.logback.core.rolling.RollingFileAppender[FILE] - openFile(,true)
call failed. java.io.FileNotFoundException:  (No such file or directory)

        at java.io.FileNotFoundException:  (No such file or directory)

        at      at java.io.FileOutputStream.open(Native Method)

        at      at
java.io.FileOutputStream.<init>(FileOutputStream.java:221)

        at      at
ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:28)

        at      at
ch.qos.logback.core.FileAppender.openFile(FileAppender.java:149)

        at      at
ch.qos.logback.core.FileAppender.start(FileAppender.java:108)

        at      at
ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:86)

        at      at
ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)

        at      at
ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)

        at      at
ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)

        at      at
ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)

        at      at
ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)

        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)

        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)

        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)

        at      at
ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)

        at      at
ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)

        at      at
ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)

        at      at
org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)

        at      at
org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)

        at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)

        at      at
org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)

        at      at
org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)

        at      at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)

        at      at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)

        at      at
org.apache.drill.exec.server.Drillbit.<clinit>(Drillbit.java:50)

Re: Drill Logging

Posted by Andy Pernsteiner <ap...@maprtech.com>.
@John re: profiles (not for logging/etc, just for profiles)

Check here for details :
https://drill.apache.org/docs/persistent-configuration-storage/

Basically, you can use the following in your drill-override.conf (on all
nodes) to get them all in one place:


sys.store.provider.zk.blobroot: "maprfs:///user/mapr/profiles",

(or whatever folder you like, but this one should work if you are running
on MapR)

You'll need to put this in the appropriate place in the config file.
Here's my config file so you can compare:

drill.exec: {
  cluster-id: "my-cluster",
  zk.connect: "10.10.10.10:5181,10.10.10.11:5181,10.10.10.12:5181"
  sys.store.provider.zk.blobroot: "maprfs:///user/mapr/profiles",
  impersonation: {
    enabled: true,
    max_chained_user_hops: 3
  }
}



On Thu, Oct 8, 2015 at 10:09 AM, John Omernik <jo...@omernik.com> wrote:

> Hello all -
>
> I am playing with Drill (I have 1.2 running right now) and I am trying to
> figure out a way to do some logging in a logical way.  I know I am running
> outside the norm, in that I am running my drill bits using marathon on
> mesos, but for a moment (unless it's THAT that is breaking my logging :)
> ignore that fact :)
>
> I am using MapR, which is nice because it lets me NFS mount my distributed
> file system (MapRFS) Thus, when I run a drillbit, I package up the
> drill-1.2.0 directory (I am using the MapR packaged version) and then in
> Marathon I create a app profile like this
>
> {
> "cmd": "./drill-1.2.0/bin/runbit --config
> /mapr/zetapoc/mesos/prod/drill/conf.std",
> "cpus": 12.0,
> "mem": 22528,
> "id": "zetadrill",
> "instances": 5,
> "uris":["hdfs:///mesos/prod/drill/drill-1.2.0.tgz"],
> "constraints": [["hostname", "UNIQUE"]]
> }
>
> Pretty basic, for non Mesos folks, it takes the URI (the tgz) downloads it
> to the Mesos Sandbox, untars it there, and runs 'runbit' using cgroups.
> Thus the memory and cpu specifications.  I am passing it a full path to the
> config location which is just the /conf  copied out of the drill-1.2.0
> directory and modified. Thus, all bits are pulling from the same conf. (I
> could package the conf in the tgz, this makes its easy to change a config
> and not have to repackage the tgz)
>
> Also, as you can see I am using the constraint to only have one per node,
> this is handy from a port conflict point of view.
>
> Ok, that out of the way, when I run it, in my drill-env.sh, I am setting:
> export DRILL_LOG_DIR="./drill-1.2.0/log"
>
> What I "think" that means is it should log inside the sandbox. And sure
> enough, when I look in the sandbox in mesos, in the log directory, there is
> a profiles folder and the sys.drill (query logs... I think?)
>
> Great.
>
> Now, in the stdout on each node that started drill, I do have the error
> below... and additionally, I don't see the drillbit.log and drillbit.out
> files.  (Is that because of the errors below?) Wouldn't these be in
> ./drill-1.2.0/log as well?
>
> Side note: If I am doing a CTAS to Parquet, one of my nodes starts spitting
> out INFO logs to the console like crazy during the write, not sure what
> that is all about...
>
> Ok, back to logging. I am trying to organize this, ideally, I want to
> understand logging deeply to meet a number of requirements
>
> 1.  I'd like all profiles/sql audit logs logged to one place.  Ideally,
> this would make it so if I click profiles on any node, I'd see the
> historical queries for all nodes, not just the one I am connected to.  Is
> this possible? Right now, I am only seeing the historical queries if I am
> connected to a node that acted as foreman for that query
>
> 2.  I'd like to keep all my logs in MapRFS with NFS, thus I'd like all
> nodes, for logfiles that have the same names (like drillbit.log and
> drillbit.out) to write to a file in the same networked location, but have
> the hostname in the logfile name.  This would allow me to log to the same
> place on all nodes, but I'd need to know how to do the hostname thing (if
> that is possible)
>
> 3. Are there any gotchas to what I am trying to do?  What about having more
> control over pruning? i.e. Can I keep the sql audit logs in a directory,
> and those will show up in the console, but have an job or setting (inside
> or outside drill) to move them to a "final" resting place for longterm
> auditing?
>
> I know some of these things may be obvious to users of drill, I have been
> having a hard time digging through the docs (for example, I am not sure
> where to find a good explanation of ENV vars that may help me here), any
> advice would be welcome!
>
> John
>
>
>
> Error on in STDOUT on sandbox.. is this hurting me?
>
>
> 16:35:22,996 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - Active log file
> name:
>
> 16:35:22,996 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - File property is
> set to []
>
> 16:35:22,998 |-ERROR in
> ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - openFile(,true)
> call failed. java.io.FileNotFoundException:  (No such file or directory)
>
>         at java.io.FileNotFoundException:  (No such file or directory)
>
>         at      at java.io.FileOutputStream.open(Native Method)
>
>         at      at
> java.io.FileOutputStream.<init>(FileOutputStream.java:221)
>
>         at      at
>
> ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:28)
>
>         at      at
> ch.qos.logback.core.FileAppender.openFile(FileAppender.java:149)
>
>         at      at
> ch.qos.logback.core.FileAppender.start(FileAppender.java:108)
>
>         at      at
>
> ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:86)
>
>         at      at
> ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)
>
>         at      at
>
> ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)
>
>         at      at
> ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
>
>         at      at
>
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)
>
>         at      at
>
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)
>
>         at      at
>
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)
>
>         at      at
>
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)
>
>         at      at
>
> ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
>
>         at      at
>
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
>
>         at      at
> org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)
>
>         at      at
> org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
>
>         at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)
>
>         at      at
> org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)
>
>         at      at
> org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)
>
>         at      at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)
>
>         at      at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)
>
>         at      at
> org.apache.drill.exec.server.Drillbit.<clinit>(Drillbit.java:50)
>
> 16:35:22,998 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type
> [ch.qos.logback.core.rolling.RollingFileAppender]
>
> 16:35:22,998 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [FILE]
>
> 16:35:23,000 |-INFO in
> ch.qos.logback.core.rolling.FixedWindowRollingPolicy@6982bec3 - No
> compression will be used
>
> 16:35:23,001 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default
> type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder]
> property
>
> 16:35:23,002 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file
> name:
>
> 16:35:23,002 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is
> set to []
>
> 16:35:23,002 |-ERROR in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - openFile(,true)
> call failed. java.io.FileNotFoundException:  (No such file or directory)
>
>         at java.io.FileNotFoundException:  (No such file or directory)
>
>         at      at java.io.FileOutputStream.open(Native Method)
>
>         at      at
> java.io.FileOutputStream.<init>(FileOutputStream.java:221)
>
>         at      at
>
> ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:28)
>
>         at      at
> ch.qos.logback.core.FileAppender.openFile(FileAppender.java:149)
>
>         at      at
> ch.qos.logback.core.FileAppender.start(FileAppender.java:108)
>
>         at      at
>
> ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:86)
>
>         at      at
> ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)
>
>         at      at
>
> ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)
>
>         at      at
> ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
>
>         at      at
>
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)
>
>         at      at
>
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)
>
>         at      at
>
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)
>
>         at      at
>
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)
>
>         at      at
>
> ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
>
>         at      at
>
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
>
>         at      at
> org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)
>
>         at      at
> org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
>
>         at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)
>
>         at      at
> org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)
>
>         at      at
> org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)
>
>         at      at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)
>
>         at      at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)
>
>         at      at
> org.apache.drill.exec.server.Drillbit.<clinit>(Drillbit.java:50)
>



-- 
 Andy Pernsteiner
 Manager, Field Enablement
ph: 206.228.0737

www.mapr.com

Now Available - Free Hadoop On-Demand Training
<http://www.mapr.com/training?utm_source=Email&utm_medium=Signature&utm_campaign=Free%20available>

Re: Drill Logging

Posted by Jacques Nadeau <ja...@dremio.com>.
I don't have a specific answer but the logging is defined in this file:

https://github.com/apache/drill/blob/master/distribution/src/resources/logback.xml

You can see that there are two loggers, one named QUERY and one named FILE.
Log query path and log path come from the two environment variables you've
identified.

I'm guessing that the issue you're having has something to do with a
failure to propagate these values.

With regards to hostname in logfile, I believe logback exposes a parameter
that can be included in the logback.xml, as we've used this before. Maybe
Kunal or Steven (cc'd) remembers more on this.



--
Jacques Nadeau
CTO and Co-Founder, Dremio

On Mon, Oct 12, 2015 at 6:13 AM, John Omernik <jo...@omernik.com> wrote:

> A follow-up, since I am using "runbit"  The line below exists. It sources
> drill-config.sh which then sources drill-env.sh. In neither of these files
> do I see the variables DRILLBIT_LOG_PATH and DRILLBIT_QUERY_LOG_PATH  so
> that may be the "file not found" error I am getting? If I set those via
> export in drill-env.sh, to be directories, then I get "File not found
> exceptions" but this time it shows the path that I am setting and claims
> the error is because the "Path" is a directory.   I guess, am I seeing some
> sort of bug due to what is expected by runbit vs. drillbit.sh. Looking at
> drillbit.sh, it looks like hit has more settings such as DRILL_OUTFILE,
> DRILL_LOGFILE, and DRILL_QUERY_FILE none of which exist in runbit.  Should
> we be having drillbit.sh and runbit be more consistent?
>
>
>
> exec $JAVA -Dlog.path=$DRILLBIT_LOG_PATH -Dlog.query.path=
> $DRILLBIT_QUERY_LOG_PATH $DRILL_ALL_JAVA_OPTS -cp $CP
> org.apache.drill.exec.server.Drillbit
>
> On Thu, Oct 8, 2015 at 12:09 PM, John Omernik <jo...@omernik.com> wrote:
>
> > Hello all -
> >
> > I am playing with Drill (I have 1.2 running right now) and I am trying to
> > figure out a way to do some logging in a logical way.  I know I am
> running
> > outside the norm, in that I am running my drill bits using marathon on
> > mesos, but for a moment (unless it's THAT that is breaking my logging :)
> > ignore that fact :)
> >
> > I am using MapR, which is nice because it lets me NFS mount my
> distributed
> > file system (MapRFS) Thus, when I run a drillbit, I package up the
> > drill-1.2.0 directory (I am using the MapR packaged version) and then in
> > Marathon I create a app profile like this
> >
> > {
> > "cmd": "./drill-1.2.0/bin/runbit --config
> > /mapr/zetapoc/mesos/prod/drill/conf.std",
> > "cpus": 12.0,
> > "mem": 22528,
> > "id": "zetadrill",
> > "instances": 5,
> > "uris":["hdfs:///mesos/prod/drill/drill-1.2.0.tgz"],
> > "constraints": [["hostname", "UNIQUE"]]
> > }
> >
> > Pretty basic, for non Mesos folks, it takes the URI (the tgz) downloads
> it
> > to the Mesos Sandbox, untars it there, and runs 'runbit' using cgroups.
> > Thus the memory and cpu specifications.  I am passing it a full path to
> the
> > config location which is just the /conf  copied out of the drill-1.2.0
> > directory and modified. Thus, all bits are pulling from the same conf. (I
> > could package the conf in the tgz, this makes its easy to change a config
> > and not have to repackage the tgz)
> >
> > Also, as you can see I am using the constraint to only have one per node,
> > this is handy from a port conflict point of view.
> >
> > Ok, that out of the way, when I run it, in my drill-env.sh, I am setting:
> > export DRILL_LOG_DIR="./drill-1.2.0/log"
> >
> > What I "think" that means is it should log inside the sandbox. And sure
> > enough, when I look in the sandbox in mesos, in the log directory, there
> is
> > a profiles folder and the sys.drill (query logs... I think?)
> >
> > Great.
> >
> > Now, in the stdout on each node that started drill, I do have the error
> > below... and additionally, I don't see the drillbit.log and drillbit.out
> > files.  (Is that because of the errors below?) Wouldn't these be in
> > ./drill-1.2.0/log as well?
> >
> > Side note: If I am doing a CTAS to Parquet, one of my nodes starts
> > spitting out INFO logs to the console like crazy during the write, not
> sure
> > what that is all about...
> >
> > Ok, back to logging. I am trying to organize this, ideally, I want to
> > understand logging deeply to meet a number of requirements
> >
> > 1.  I'd like all profiles/sql audit logs logged to one place.  Ideally,
> > this would make it so if I click profiles on any node, I'd see the
> > historical queries for all nodes, not just the one I am connected to.  Is
> > this possible? Right now, I am only seeing the historical queries if I am
> > connected to a node that acted as foreman for that query
> >
> > 2.  I'd like to keep all my logs in MapRFS with NFS, thus I'd like all
> > nodes, for logfiles that have the same names (like drillbit.log and
> > drillbit.out) to write to a file in the same networked location, but have
> > the hostname in the logfile name.  This would allow me to log to the same
> > place on all nodes, but I'd need to know how to do the hostname thing (if
> > that is possible)
> >
> > 3. Are there any gotchas to what I am trying to do?  What about having
> > more control over pruning? i.e. Can I keep the sql audit logs in a
> > directory, and those will show up in the console, but have an job or
> > setting (inside or outside drill) to move them to a "final" resting place
> > for longterm auditing?
> >
> > I know some of these things may be obvious to users of drill, I have been
> > having a hard time digging through the docs (for example, I am not sure
> > where to find a good explanation of ENV vars that may help me here), any
> > advice would be welcome!
> >
> > John
> >
> >
> >
> > Error on in STDOUT on sandbox.. is this hurting me?
> >
> >
> > 16:35:22,996 |-INFO in
> > ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - Active log file
> > name:
> >
> > 16:35:22,996 |-INFO in
> > ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - File property is
> > set to []
> >
> > 16:35:22,998 |-ERROR in
> > ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - openFile(,true)
> > call failed. java.io.FileNotFoundException:  (No such file or directory)
> >
> >         at java.io.FileNotFoundException:  (No such file or directory)
> >
> >         at      at java.io.FileOutputStream.open(Native Method)
> >
> >         at      at
> > java.io.FileOutputStream.<init>(FileOutputStream.java:221)
> >
> >         at      at
> >
> ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:28)
> >
> >         at      at
> > ch.qos.logback.core.FileAppender.openFile(FileAppender.java:149)
> >
> >         at      at
> > ch.qos.logback.core.FileAppender.start(FileAppender.java:108)
> >
> >         at      at
> >
> ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:86)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)
> >
> >         at      at
> > ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)
> >
> >         at      at
> >
> ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
> >
> >         at      at
> >
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
> >
> >         at      at
> > org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)
> >
> >         at      at
> > org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
> >
> >         at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)
> >
> >         at      at
> > org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)
> >
> >         at      at
> > org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)
> >
> >         at      at
> > org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)
> >
> >         at      at
> > org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)
> >
> >         at      at
> > org.apache.drill.exec.server.Drillbit.<clinit>(Drillbit.java:50)
> >
> > 16:35:22,998 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> > About to instantiate appender of type
> > [ch.qos.logback.core.rolling.RollingFileAppender]
> >
> > 16:35:22,998 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> > Naming appender as [FILE]
> >
> > 16:35:23,000 |-INFO in
> > ch.qos.logback.core.rolling.FixedWindowRollingPolicy@6982bec3 - No
> > compression will be used
> >
> > 16:35:23,001 |-INFO in
> > ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming
> default
> > type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder]
> > property
> >
> > 16:35:23,002 |-INFO in
> > ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file
> > name:
> >
> > 16:35:23,002 |-INFO in
> > ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is
> > set to []
> >
> > 16:35:23,002 |-ERROR in
> > ch.qos.logback.core.rolling.RollingFileAppender[FILE] - openFile(,true)
> > call failed. java.io.FileNotFoundException:  (No such file or directory)
> >
> >         at java.io.FileNotFoundException:  (No such file or directory)
> >
> >         at      at java.io.FileOutputStream.open(Native Method)
> >
> >         at      at
> > java.io.FileOutputStream.<init>(FileOutputStream.java:221)
> >
> >         at      at
> >
> ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:28)
> >
> >         at      at
> > ch.qos.logback.core.FileAppender.openFile(FileAppender.java:149)
> >
> >         at      at
> > ch.qos.logback.core.FileAppender.start(FileAppender.java:108)
> >
> >         at      at
> >
> ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:86)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)
> >
> >         at      at
> > ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)
> >
> >         at      at
> >
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)
> >
> >         at      at
> >
> ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
> >
> >         at      at
> >
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
> >
> >         at      at
> > org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)
> >
> >         at      at
> > org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
> >
> >         at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)
> >
> >         at      at
> > org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)
> >
> >         at      at
> > org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)
> >
> >         at      at
> > org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)
> >
> >         at      at
> > org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)
> >
> >         at      at
> > org.apache.drill.exec.server.Drillbit.<clinit>(Drillbit.java:50)
> >
>

Re: Drill Logging

Posted by John Omernik <jo...@omernik.com>.
A follow-up, since I am using "runbit"  The line below exists. It sources
drill-config.sh which then sources drill-env.sh. In neither of these files
do I see the variables DRILLBIT_LOG_PATH and DRILLBIT_QUERY_LOG_PATH  so
that may be the "file not found" error I am getting? If I set those via
export in drill-env.sh, to be directories, then I get "File not found
exceptions" but this time it shows the path that I am setting and claims
the error is because the "Path" is a directory.   I guess, am I seeing some
sort of bug due to what is expected by runbit vs. drillbit.sh. Looking at
drillbit.sh, it looks like hit has more settings such as DRILL_OUTFILE,
DRILL_LOGFILE, and DRILL_QUERY_FILE none of which exist in runbit.  Should
we be having drillbit.sh and runbit be more consistent?



exec $JAVA -Dlog.path=$DRILLBIT_LOG_PATH -Dlog.query.path=
$DRILLBIT_QUERY_LOG_PATH $DRILL_ALL_JAVA_OPTS -cp $CP
org.apache.drill.exec.server.Drillbit

On Thu, Oct 8, 2015 at 12:09 PM, John Omernik <jo...@omernik.com> wrote:

> Hello all -
>
> I am playing with Drill (I have 1.2 running right now) and I am trying to
> figure out a way to do some logging in a logical way.  I know I am running
> outside the norm, in that I am running my drill bits using marathon on
> mesos, but for a moment (unless it's THAT that is breaking my logging :)
> ignore that fact :)
>
> I am using MapR, which is nice because it lets me NFS mount my distributed
> file system (MapRFS) Thus, when I run a drillbit, I package up the
> drill-1.2.0 directory (I am using the MapR packaged version) and then in
> Marathon I create a app profile like this
>
> {
> "cmd": "./drill-1.2.0/bin/runbit --config
> /mapr/zetapoc/mesos/prod/drill/conf.std",
> "cpus": 12.0,
> "mem": 22528,
> "id": "zetadrill",
> "instances": 5,
> "uris":["hdfs:///mesos/prod/drill/drill-1.2.0.tgz"],
> "constraints": [["hostname", "UNIQUE"]]
> }
>
> Pretty basic, for non Mesos folks, it takes the URI (the tgz) downloads it
> to the Mesos Sandbox, untars it there, and runs 'runbit' using cgroups.
> Thus the memory and cpu specifications.  I am passing it a full path to the
> config location which is just the /conf  copied out of the drill-1.2.0
> directory and modified. Thus, all bits are pulling from the same conf. (I
> could package the conf in the tgz, this makes its easy to change a config
> and not have to repackage the tgz)
>
> Also, as you can see I am using the constraint to only have one per node,
> this is handy from a port conflict point of view.
>
> Ok, that out of the way, when I run it, in my drill-env.sh, I am setting:
> export DRILL_LOG_DIR="./drill-1.2.0/log"
>
> What I "think" that means is it should log inside the sandbox. And sure
> enough, when I look in the sandbox in mesos, in the log directory, there is
> a profiles folder and the sys.drill (query logs... I think?)
>
> Great.
>
> Now, in the stdout on each node that started drill, I do have the error
> below... and additionally, I don't see the drillbit.log and drillbit.out
> files.  (Is that because of the errors below?) Wouldn't these be in
> ./drill-1.2.0/log as well?
>
> Side note: If I am doing a CTAS to Parquet, one of my nodes starts
> spitting out INFO logs to the console like crazy during the write, not sure
> what that is all about...
>
> Ok, back to logging. I am trying to organize this, ideally, I want to
> understand logging deeply to meet a number of requirements
>
> 1.  I'd like all profiles/sql audit logs logged to one place.  Ideally,
> this would make it so if I click profiles on any node, I'd see the
> historical queries for all nodes, not just the one I am connected to.  Is
> this possible? Right now, I am only seeing the historical queries if I am
> connected to a node that acted as foreman for that query
>
> 2.  I'd like to keep all my logs in MapRFS with NFS, thus I'd like all
> nodes, for logfiles that have the same names (like drillbit.log and
> drillbit.out) to write to a file in the same networked location, but have
> the hostname in the logfile name.  This would allow me to log to the same
> place on all nodes, but I'd need to know how to do the hostname thing (if
> that is possible)
>
> 3. Are there any gotchas to what I am trying to do?  What about having
> more control over pruning? i.e. Can I keep the sql audit logs in a
> directory, and those will show up in the console, but have an job or
> setting (inside or outside drill) to move them to a "final" resting place
> for longterm auditing?
>
> I know some of these things may be obvious to users of drill, I have been
> having a hard time digging through the docs (for example, I am not sure
> where to find a good explanation of ENV vars that may help me here), any
> advice would be welcome!
>
> John
>
>
>
> Error on in STDOUT on sandbox.. is this hurting me?
>
>
> 16:35:22,996 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - Active log file
> name:
>
> 16:35:22,996 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - File property is
> set to []
>
> 16:35:22,998 |-ERROR in
> ch.qos.logback.core.rolling.RollingFileAppender[QUERY] - openFile(,true)
> call failed. java.io.FileNotFoundException:  (No such file or directory)
>
>         at java.io.FileNotFoundException:  (No such file or directory)
>
>         at      at java.io.FileOutputStream.open(Native Method)
>
>         at      at
> java.io.FileOutputStream.<init>(FileOutputStream.java:221)
>
>         at      at
> ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:28)
>
>         at      at
> ch.qos.logback.core.FileAppender.openFile(FileAppender.java:149)
>
>         at      at
> ch.qos.logback.core.FileAppender.start(FileAppender.java:108)
>
>         at      at
> ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:86)
>
>         at      at
> ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)
>
>         at      at
> ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
>
>         at      at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)
>
>         at      at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)
>
>         at      at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)
>
>         at      at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)
>
>         at      at
> ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
>
>         at      at
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
>
>         at      at
> org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)
>
>         at      at
> org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
>
>         at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)
>
>         at      at
> org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)
>
>         at      at
> org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)
>
>         at      at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)
>
>         at      at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)
>
>         at      at
> org.apache.drill.exec.server.Drillbit.<clinit>(Drillbit.java:50)
>
> 16:35:22,998 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type
> [ch.qos.logback.core.rolling.RollingFileAppender]
>
> 16:35:22,998 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [FILE]
>
> 16:35:23,000 |-INFO in
> ch.qos.logback.core.rolling.FixedWindowRollingPolicy@6982bec3 - No
> compression will be used
>
> 16:35:23,001 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default
> type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder]
> property
>
> 16:35:23,002 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file
> name:
>
> 16:35:23,002 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is
> set to []
>
> 16:35:23,002 |-ERROR in
> ch.qos.logback.core.rolling.RollingFileAppender[FILE] - openFile(,true)
> call failed. java.io.FileNotFoundException:  (No such file or directory)
>
>         at java.io.FileNotFoundException:  (No such file or directory)
>
>         at      at java.io.FileOutputStream.open(Native Method)
>
>         at      at
> java.io.FileOutputStream.<init>(FileOutputStream.java:221)
>
>         at      at
> ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:28)
>
>         at      at
> ch.qos.logback.core.FileAppender.openFile(FileAppender.java:149)
>
>         at      at
> ch.qos.logback.core.FileAppender.start(FileAppender.java:108)
>
>         at      at
> ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:86)
>
>         at      at
> ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:96)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:317)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:196)
>
>         at      at
> ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:182)
>
>         at      at
> ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
>
>         at      at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:149)
>
>         at      at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:135)
>
>         at      at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:99)
>
>         at      at
> ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:49)
>
>         at      at
> ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
>
>         at      at
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:148)
>
>         at      at
> org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:85)
>
>         at      at
> org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
>
>         at      at org.slf4j.LoggerFactory.bind(LoggerFactory.java:129)
>
>         at      at
> org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:108)
>
>         at      at
> org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:302)
>
>         at      at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:276)
>
>         at      at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:288)
>
>         at      at
> org.apache.drill.exec.server.Drillbit.<clinit>(Drillbit.java:50)
>