Logback with rsyslog

In company I work for, developers don't have any access to Live servers. While it is good from the responsibility division reasons, it makes problem and error tracking painful. Most often we need access to log files without asking somebody from operations team every single time.

To overcome this, we went predictable way of setting up company-wide log aggregation server. While there is plethora of solutions, one is quite easy to setup if you are on Unix/Linux - rsyslog It is widely used to provide standard syslog feature so there is good chance that you have it installed already.

I will not talk much about rsyslog server. It listens usualy on UDP port 514 and has configuration file /etc/rsyslog.conf. Excelent article about installation and basic configuration is here.

Any (client host) rsyslog can be configured to forward it's syslog messages into server rsyslog. This might be right way, when you develop native or RoR application and you log into local syslog, but Java world has it's well established logging libraries, namely Logback or Log4j. Both of them provide appanders capable of sending log events into rsyslog server, while logging into local files as usualy.

Anyway, if you are already logging directly into local syslog, and you need to forward messages into log server, just add to the end of /etc/rsyslog.conf file.

*.* @logs.mycompany.com:514

You can use DNS name or IP addres of your rsyslog server. 514 is default rsyslog port.

To log from java directly to rsyslog server, skipping local syslog completely, add SyslogAppender into logback.xml.
Logback does not provide explicit configuration for TAG aka APP-NAME aka $programname, but it can be emulated by using special syntax of the first word of the log message.
It must start with ' ' (whitespace) and end with ':' (colon) See ' mycoolapp:' in suffixPattern element value. Logback configuration feature ticket exist, but it seems to be abandoned. I don't use Log4J, so here is just a link to article about Log4j and syslog. But I don't think it covers TAG usage.

Back on server, log messages from muliple hosts and applications are written, by default, into single /vsr/log/messages file, making it quite messy. Fortunately rsyslog provides easy way of routing messages coming from different hosts or applications into different files.

You can split messages using hostname or ip address they are coming from, as described here or you can split them on log message content, as described here. You can throw them away too, as described here.

What we choose, is routing messages belonging to same application into single log file. Messages are coming from different hosts because application runs in cluster. Every log line contains hostname, so origin still can be recognized.

if $programname == 'mycoolapp' then /var/log/mycoolapp/mycoolapp.log

To make this work, client must send TAG ($programname) field correctly as described above in logback.xml

Happy rsyslogging

Openshift System properties and Environment variables

For cloud deployable application, it is advisable to create them as much self-contained as possible. If application allows some configuration, these settings should be packaged inside war file and used as default values, while value override mechanism is provided.

Linux Environment variables

Unfortunately, following (usual) way of setting environment variable will not work on Openshift.

ctl_app stop jbossews
export MY_ENV_VAR="my_env_var_value"
ctl_app start jbossews

To be precise, JAVA_OPTS_EXT variable set like this, will not visible to java process running your application. To set it properly, you have to do it using Openshift rhc tool or using shortcut

echo "my_env_var_value" > ~/.env/user_vars/MY_ENV_VAR

An now you can in your webapp get variable value

  String my_env_var = System.getenv("MY_ENV_VAR"); //"my_env_var_value"
  if (my_env_var == null) {
    my_env_var = "Default value..."; //I told you not to depend on external configuration and provide default values...
  }

Java System Properties

System Properties are most commonly used to pass parameters into Java application. They are specified as java "-D" prefixed command-line parameters:

java -Dmyapp.param=whatever ...

then they can be obtained inside application

String param = System.getProperty("myapp.param"); //"whatever"

But Openshift managed servers are started using ctl_app start ... (or gears start ...) command and we are not directly in control of executing java so we can't add "-D" parameters.

Trick is to use JAVA_OPTS_EXT evironment variable. Since we know how to set Openshift Environment variable, it is just matter of:

echo "-Dmyapp.param=myapp.value" > .env/user_vars/JAVA_OPTS_EXT

...then restart your server...

ctl_app stop jbossews
ctl_app start jbossews

...and enjoy fruits of your effort (look for -Dmyapp.param=myapp.value)...

[wotan-anthavio.rhcloud.com 52d184e45973ca0bc0000088]\> jps -mlv
29444 sun.tools.jps.Jps -mlv -Dapplication.home=/usr/lib/jvm/java-1.7.0-openjdk-1.7.0.45 -Xms8m
24633 org.apache.catalina.startup.Bootstrap start -Xmx256m -XX:MaxPermSize=102m -XX:+AggressiveOpts -DOPENSHIFT_APP_UUID=52d184e45973ca0bc0000088 -Djava.util.logging.config.file=/var/lib/openshift/52d184e45973ca0bc0000088/jbossews//conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.net.preferIPv4Stack=true -Dfile.encoding=UTF-8 -Djava.net.preferIPv4Stack=true -Dmyapp.param=myapp.value -Dcatalina.base=/var/lib/openshift/52d184e45973ca0bc0000088/jbossews/ -Dcatalina.home=/var/lib/openshift/52d184e45973ca0bc0000088/jbossews/ -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/openshift/52d184e45973ca0bc0000088/jbossews//tmp

Deploy to Openshift from Github repository

On Cloudbees RUN@Cloud or Jelastic cloud PaaS, it is simple to build application war on your devbox and then use provided web interface to simply upload and deploy it.

Openshift does not offer such deployment option right away, and similarily to Heroku it encourages you to do builds and deployments via git push commit hook. First I'll do deployment to Openshift encouraged and documented way, but because it actually is possible to deploy externaly built war to Openshift, I'll describe how to perform it too.

I have existing quite simple, Maven built, multimodule application Wotan hosted in Github repository. One of it's submodules - wotan-browser is web application packaged as war. Plan is to deploy this webapp to Openshift.

Create Account and some Gears

Openshift account comes with 3 free Gears (simultaneously running JVMs). I've signed in and then created Gear named "wotan" with "Tomcat 7 (JBoss EWS 2.0)" cartridge. Same can be done using rhc app create wotan jbossews-2.0 command I also added "Jenkins Client" cartridge, which creates Jenkins instance that occupies second Gear. To execute Jenkins build, third and last free Gear is required. Since that escalated quickly, I'll later show how to build web application without Jenkins to save two Gears

In order to simplify authentication, I've configured same ssh public key I'm using for Github on Settings page. I strongly encourage you to do it as well. If it happend that you do not have any ssh key, create one using ssh-keygen or puttygen if you are on Windows.

What Openshift provides

Openshift gives you real linux system account, which is nice. It's big difference comparing to other cloud platforms, where you have only limited interface (web or SDK) to interact with your server and applications.
You can login into...

ssh 52d184e45973ca0bc0000088@wotan-anthavio.rhcloud.com

...look around for a while...

[wotan-anthavio.rhcloud.com 52d184e45973ca0bc0000088]\> ls -gG
total 20
drwxr-xr-x.  4 4096 Jan 14 15:19 app-deployments
drwxr-xr-x.  4 4096 Jan 11 12:52 app-root
drwxr-xr-x.  3 4096 Jan 11 12:53 git
drwxr-xr-x. 13 4096 Jan 11 12:53 jbossews
drwxr-xr-x.  8 4096 Jan 11 12:57 jenkins-client

...but most interesting directories are...

• jbossews - Server from Tomcat 7 (JBoss EWS 2.0) cartridge. This is ultimate place where webapps and logs will be. If you have picked another cartridge type for your application, your directory will be different of course
• git - Git repository with default simple web application

Git repository comes prepopulated with default simple web application. I'm gonna replace it with my Github repository content, but it is worth to at least check it out and look how the vanilla pom.xml looks like.

git clone ssh://52d184e45973ca0bc0000088@wotan-anthavio.rhcloud.com/~/git/wotan.git/

Quite important is .openshift directory because it contains various Openshift metadata and configuration. See documentation page

Default simple application is also deployed on Gear creation and Jenkins instance with preconfigured build Job You can start new build and see on Applications page, how one Gear will become occupied by build process and disappears after while. It is also useful to examine build console output to see what precisely get executed and how - java version, maven parameters, etc...

Deploy using Openshift Jenkins

On my devbox I have my Github repo checked out (On Mac OSX and Windows7 PC with Cygwin)

git clone git@github.com:anthavio/wotan.git

Now merge Github repo into Openshift repo. Steps are taken from stackoverflow so I'll just list commands

git remote add openshift -f ssh://52d184e45973ca0bc0000088@wotan-anthavio.rhcloud.com/~/git/wotan.git/
git merge openshift/master -s recursive -X ours
git push openshift HEAD

Every git push openshift HEAD starts new Jenkins build. It fails at first because pom.xml is not ready for Openshift and tweaks has to be done. Let's examine these tweaks.

Maven pom.xml changes for Openshift

Whole pom.xml can be found here

• To use dependencies not present in Maven Central repository, additional repository (sonatype-oss-public) has been added
• You might seen in vanilla Openshift pom.xml slightly changed maven-war-plugin configuration. Contract for deployment is that all deployable artifacts must be present in webapps directory and have nice file name, because this name will became part of url
• Turn off maven-enforcer-plugin - this might not be necessary for most of developers. I enforce conservative Java6, but Openshift runs on Java7

Skip OpenShift git repository

Actually you need not to use Openshift git repository at all. Just go to the Jenkins Job configuration and change Git repository URL from ssh://52d184e45973ca0bc0000088@wotan-anthavio.rhcloud.com/~/git/wotan.git to use directly Github repository https://github.com/anthavio/wotan.git and forget Openshift git repo forever...

Deploy pre-built war

Now I'll use another web application of mine - Disquo. I'll build war on my devbox and deploy it manualy. No Jenkins involved.

# build war localy
git clone git@github.com:anthavio/disquo.git /tmp/disquo.git
cd /tmp/disquo.git
mvn clean package -Dmaven.test.skip=true

# upload assembled war
scp disquo-web/target/disquo-web-1.0.0-SNAPSHOT.war 52d184e45973ca0bc0000088@wotan-anthavio.rhcloud.com:~/app-root/repo/webapps/disquo.war
ssh 52d184e45973ca0bc0000088@wotan-anthavio.rhcloud.com
# stop tomcat & deploy webapp & start tomcat
ctl_app stop jbossews
cp app-root/repo/webapps/disquo.war jbossews/webapps
ctl_app start jbossews

# Check Tomcat log file
tail -f jbossews/logs/catalina.out

Deploying this way has nice effects

• Jenkins gear and building gear are not required, can be removed and all 3 gears are avaliable for running applications
• Multiple applications can be deployed into single Tomcat gear

Happy Openshift deployments folks!

nslookup vs /etc/hosts

TLDR: nslookup command does NOT use /etc/hosts for domain name to IP resolution.

Recently I needed to simulate outage of Disqus server providing REST endpoints for commenting.

Because client application, using this service, was deployed into horrible CMS server, changing URL for Disqus service was quite painful. OS on the server is Red Hat Enterprise Linux, so I decided to simply add entry into /etc/hosts translating "disqus.com" domain name to 127.0.0.1 (localhost). Purpose was to hijack DNS resolution into real public Disqus IP address, obtained from DNS server, to make disqus.com calls fail. Dead simple.

I've added line 127.0.0.1 disqus.com into /etc/hosts and executed

nslookup disqus.com

expecting to see the difference, but there wasn't any and nslookup was still returning Disqus public IP address. Suspecting DNS caching for causing this, I've started looking for a way to flush DNS translation cache. Linux standard way seems to have nscd daemon running and refreshing it

nscd -I hosts

should do the trick. But surprisingly, nscd was not running on that server. Neither did any of named, bind, rscd, dnsmasq...

Probably only way to flush dns cache in this situation could be restart of whole networking subsystem (/etc/init.d/network restart), but that wasn't something I could do on that server.

Then, just to be double sure, I executed

ping disqus.com

and spotted that it is pinging 127.0.0.1 as I wanted! But nslookup, executed again, was still showing public Disqus IP address!
As it has turned out that, nslookup is always doing DNS server lookup and it is ignoring your /etc/hosts file

Lesson learned - Don't test your /etc/hosts changes with nslookup. Use ping instead.

It is still some DNS caching done in Java, because ping reflected IP changes immediately, but application running in Java server changed IP after while. I haven't measured it precisely, but it seemed to be about one minute. As it turned out, this delay was actually caused by Varnish and has nothing to do with Java... sorry

All of this happened of RHEL 5.7 (cat /etc/*-release)

PS: Just for completeness. To make sure that /etc/hosts file will take precedence over DNS servers, in process of hostname resolution, following should be true

• File /etc/host.conf should contain line order hosts,bind
• File /etc/nsswitch.conf should contain line hosts: files dns