Monitoring Informix with the Elastic Stack
Posted: 8 December, 2018 Filed under: Monitoring | Tags: elasticsearch, elk, informix, kibana, logstash Leave a commentIntroduction
If you’re not familiar with the Elastic Stack it is a suite of products for ingesting data or logs, searching, analysing and visualising. There is a good overview over at the Elastic web site of how it can be put together. I say “can” because the stack is very flexible and, for example, you can send JSON documents to Elasticsearch via a REST API, rather than use Filebeat or Logstash.
This blog post is mostly concerned with ingesting the Informix online log with Filebeat, recognising certain types of log line that can occur and tagging the file using rules set up in Logstash, before sending it to Elasticsearch for storage and indexing. Finally Kibana can be used to visualise the data stored in Elasticsearch.
It’s easy to see how this could be scaled up to provide a single place to visualise logs from multiple instances and it would be fairly trivial to add in other logs too, like the Informix bar logs and logs from the operating system.
At IIUG 2018 in Arlington, VA I presented a talk entitled DevOps for DBAs, which demonstrated the Docker set up now described below but I hadn’t at the time documented the full set up at the time. Here it is!
Practical demonstration with Docker containers
Overview
This demonstration sets up two containers: one running Informix Developer Edition and Filebeat to collect and ship logs:
- Informix 12.10.FC12W1DE, listening on port 9088/tcp for onsoctcp connections.
- Filebeat 6.5.2.
and the other running the Elasticstack components as follows:
- Logstash 6.5.2, listening on port 5044/tcp.
- Elasticsearch 6.5.2, listening on port 9200/tcp.
- Kibana 6.5.2, listening on port 5601/tcp.
Access to Kibana is via your favourite web browser running on your desktop. Nginx will be listening on port 80 so you can simply access http://localhost/
For a secure production implementation it’s recommended that you use Nginx with HTTPS as a reverse proxy for the Kibana web service as shown in the diagram. We’ll be using Nginx in this demonstration, rather than connecting to Kibana directly, but we won’t be configuring SSL; there are plenty of online guides about how to do this. Also communication between Filebeat and Logstash should be encrypted: this blog post doesn’t cover this.
The above versions are current at the time of writing (December 2018). Elasticstack moves very quickly so it is likely these will not be the latest versions by the time you read this. The idea of this blog post is that you should just be able to copy and paste the commands and end up with a working system but you shouldn’t be surprised if things don’t work perfectly if your versions don’t match the above. For example, in between beginning this blog post and finishing it, version 6.5.x was released with improved default security settings, with services only listening on the loopback interface without reconfiguration.
Running the whole Elasticstack in Docker plus Informix does require a reasonable amount of memory and I’d suggest a minimum of 2.5 GB to be allocated to the Docker Engine.
Docker network
To provide name resolution between the containers we are going to start by creating a docker network:
docker network create --driver bridge my_informix_elk_stack
Elastic Stack installation
Docker container
We’ll start by setting up the Elastic Stack Docker container which will be using on a (minimal) Debian installation. In a terminal run:
docker pull debian
docker run -it --name elasticstack_monitoring -p 80:80 -p 5044:5044 --hostname elasticstack -e "GF_SECURITY_ADMIN_PASSWORD=secret" --net my_informix_elk_stack debian
Your terminal should now be inside the Docker container and logged in as root.
To avoid some issues with debconf when installing packages run:
echo 'debconf debconf/frontend select Noninteractive' | debconf-set-selections
Install Java
Run these commands to install some the software-properties-common package and then install OpenJDK 8, which is required by Elasticsearch and Logstash. Java 9 should be fine too.
The Debian Docker image does not come with many packages pre-installed so I am also going to install vim for editing files later plus a few other essentials; you may prefer nano or another editor.
apt-get update
apt-get install software-properties-common gnupg vim wget apt-transport-https openjdk-8-jre
The Debian Docker container is a basic installation so this short list of packages have hundreds of dependencies.
Check the Java version:
# java -version
openjdk version "1.8.0_181"
OpenJDK Runtime Environment (build 1.8.0_181-8u181-b13-2~deb9u1-b13)
OpenJDK 64-Bit Server VM (build 25.181-b13, mixed mode)
Install Elasticsearch
The Elasticsearch installation is more straightforward than Oracle Java and follows standard Linux methods for setting up and installing from a third party software repository.
First we install the repository’s key:
wget -qO - https://packages.elastic.co/GPG-KEY-elasticsearch | apt-key add -
Then add the repository:
echo "deb https://artifacts.elastic.co/packages/6.x/apt stable main" | tee -a /etc/apt/sources.list.d/elastic-6.x.list
We need the HTTPS transport package installing before we can proceed to install.
apt-get update
apt-get install elasticsearch
Elasticsearch will work right out of the box which is fine for the purposes of this demonstration and (after we start the service) will be listening on localhost only on ports 9200 for the REST API and 9300 for node communication.
Install Kibana
This is installed from the Elasticstack repository added above:
apt-get install kibana
Again Kibana doesn’t require any reconfiguration for the purposes of this demonstration and will listen on localhost only on port 5601.
Start Kibana by running:
service kibana start
Now that Kibana is running start Elasticsearch by running:
service elasticsearch start
It’s worth noting as this point that modern Debian distributions use systemd but this doesn’t work in non-privileged Docker containers. For reference the systemd equivalents for this are:
systemctl daemon-reload
systemctl enable kibana
systemctl enable elasticsearch
systemctl start kibana
systemctl start elasticsearch
This commands also ensure the service starts on boot.
As Kibana is only listening on localhost and therefore unreachable from an external web browser, we will set up Nginx as a reverse proxy. This is a more secure configuration and recommended for any production implementation because only Nginx is directly exposed to the internet and not Kibana.
Install Nginx as a reverse proxy
Start by installing Nginx:
apt-get install nginx
Edit the file /etc/nginx/sites-available/default and in the location / section add the line:
proxy_pass http://localhost:5601;
Comment out the line beginning with try_files.
It should look something like this:
location / {
# First attempt to serve request as file, then
# as directory, then fall back to displaying a 404.
proxy_pass http://localhost:5601;
#try_files $uri $uri/ =404;
}
Don’t forget the semi-colon!
Start nginx:
service nginx start
Install Logstash
An installation procedure that by now should look familiar:
apt-get install logstash
Our Logstash configuration will be in two parts:
- A standard out of the box configuration for receiving files from Filebeat and sending them to Elasticsearch: for this copy /etc/logstash/logstash-sample.conf to /etc/logstash/conf.d/logstash.conf
- A custom config file, /etc/logstash/conf.d/informix.conf, for parsing the Informix online log.
I intend to update and improve the Logstash config for filtering the Informix online log and it’s available on my Github page at https://github.com/skybet/informix-helpers/blob/master/logstash/informix.conf. Download it locally and then you can copy it to your Docker container as follows:
docker cp informix.conf elasticstack_monitoring:/etc/logstash/conf.d/informix.conf
The Informix config file requires that Filebeat tags the file with “[field][informix] = true“; this condition is trivial to remove if you wish.
Check the Logstash configuration with:
/usr/share/logstash/bin/logstash -t --path.settings /etc/logstash
Finally start Logstash with:
/usr/share/logstash/bin/logstash --path.settings /etc/logstash
You could also use systemd to do this.
Informix installation
Informix Developer Edition Docker container
Now we are going to set up the Informix container to monitor. On your workstation in another terminal run:
$ docker pull ibmcom/informix-developer-database
docker run -it --name iif_developer_edition --privileged -p 9088:9088 -p 9089:9089 -p 27017:27017 -p 27018:27018 -p 27883:27883 --hostname ifxserver --net my_informix_elk_stack -e LICENSE=accept ibmcom/informix-developer-database:latest
It’s worth noting that if you exit the shell the Informix DE Docker container will stop. You can start it again with:
docker start iif_developer_edition -i
This latest version containing 12.10.FC12W1 doesn’t return you to the prompt after the engine starts, so you’ll need to open an interactive container in another terminal window as follows:
docker exec -it iif_developer_edition /bin/bash
Now both Docker containers are running you should be able to test name resolution and connectivity both ways with ping.
From the Informix container:
informix@ifxserver:/$ ping elasticstack_monitoring
From the Elastic Stack container:
root@elasticstack2:/# ping iif_developer_edition
These names belong to the containers and are not necessarily their host names.
While you’re still logged in as Informix set MSG_DATE to 1 which is required for my Logstash configuration:
onmode -wf MSG_DATE=1
This means (nearly) all online log messages will be prefixed with the date (MM/DD/YY format) and time (HH:MM:SS format).
You’ll be logged in as user informix which can sudo to root as follows:
sudo -i
Install Filebeat
In the Informix container it’s more of the same to install Filebeat:
apt-get update
apt-get install vim wget apt-transport-https
wget -qO - https://packages.elastic.co/GPG-KEY-elasticsearch | apt-key add -
echo "deb https://artifacts.elastic.co/packages/6.x/apt stable main" | tee -a /etc/apt/sources.list.d/elastic-6.x.list
apt-get update
apt-get install filebeat
Filebeat’s configuration file is /etc/filebeat/filebeat.yml. If you’re not familiar with yml files correct indentation with two spaces per level is absolutely essential; yml files rely on this for structure instead of any braces or brackets. Lines beginning with a dash indicate an array.
onstat -c | grep MSGPATH reveals that the Informix online log file resides at /opt/ibm/data/logs/online.log and we want Filebeat to ingest this and pass it to Logstash running in the other container for parsing.
The Informix online log quite often contains wrapped lines and these generally don’t start with a timestamp or date of any kind.
Edit the file and add the following configuration directly under filebeat.inputs:
- type: log
enabled: true
paths:
- /opt/ibm/data/logs/online.log
fields:
informix: true
multiline.pattern: '^[0-9][0-9]'
multiline.negate: true
multiline.match: after
Finally set up the output by commenting out (add a ‘#’) to all parts of output.elasticsearch and uncommenting section output.logstash. Set hosts in this section to [“elasticstack_monitoring:5044”].
Start filebeat by running:
service filebeat start
You should see the message: Config OK.
Using Kibana
You should now be able to log into Kibana on http://localhost/ and add an index on filebeat*.
Then in the Discover section you should be able to see Informix log lines coming into the system and how they have been tagged.
If you wish to improve and test the parsing of particular log entries it is simple enough to create ones yourself in the Informix container like this:
echo "12/08/18 17:00:00 My Informix log line" >> /opt/ibm/data/logs/online.log
This particular blog post is going to end shortly. Kibana is a big subject and at this stage of my Elasticstack DevOps journey, I don’t feel qualified to write a blog on the subject. Once I’ve progressed further I may do a follow-on post.
The tagging of events in the online log like the checkpoint duration and its assignment to variable informix.ckpt_duration should allow you do easily do searches based on this and visualise them in dashboards.
Good luck!
Monitoring Informix with Grafana
Posted: 3 January, 2018 Filed under: Instance and operating system tuning, Monitoring | Tags: Grafana, Graphite, InfluxDB, informix 6 CommentsIntroduction
In a presentation I gave at IIUG 2017 titled Making system monitoring better I showed, without much detail, how Grafana is a powerful tool for visualising what is happening within your Informix server. Performance metrics from your database server are collected at regular (usually 10 second) intervals and stored in a time-series database which can be used as the source for dashboards containing dynamic graphs and other ways of presenting the data. For the DBA the benefits are legion:
- Quickly change the time range to zoom into when problems occurred or zoom out to see trends.
- Correlate various database metrics and combine then with related operating system, network, storage or application metrics.
- Get a truer picture of your busy periods, capacity, the effect of scheduled jobs etc.
- Faster problem resolution because a lot of data can be visualised at once.
You might be able to think of some others.
The talk also touched on the CAMS acronym:
Culture
Automation
Measurement
Sharing
So you shouldn’t keep your dashboards to yourself: share them with other technical teams or everyone in your company. This has the added benefit of more eyes and others can learn to spot database problems, or when they are probably not database problems, by referring to these.
Why Grafana?
There are a number of tools which appear to do a similar job:
- Prometheus
- Graphite
- Grafana
- AGS Sentinel
- Brunia
You perhaps haven’t heard of Brunia: it is the code name for a prototype monitoring tool that may replace Informix Open Admin Tool (OAT) in the future. It was demonstrated at IIUG 2017 and is probably closest to Prometheus in its execution. AGS Sentinel is the monitoring add-on to the popular ServerStudio suite for Informix. The rest are popular open source tools which other teams in your organisation are probably already using.
Some of the tools listed above can also produce events or alerts when a trigger condition occurs and automatically pass this up a stack to PagerDuty or another call-out system. An example of such a stack is Prometheus -> Alertmanager -> PagerDuty -> StatusPage
There are a lot of ways of implementing a full monitoring stack with choices to make about data collection, storing, visualisation, analysis and alerting. In this blog post I am going to concentrate on a simple set up where we collect Informix metrics, pass them to InfluxDB using a REST API and visualise in Grafana. For a fuller discussion of the benefits of the three open source technologies mentioned above I highly recommend reading this blog post from Loom Systems written in June 2017, Prometheus vs. Grafana vs. Graphite – A Feature Comparison.
In case you’re not going to read the LS blog it’s worth emphasising what the InfluxDB/Grafana solution I am about to describe does not provide:
- There is little in the way of monitoring and alerting features.
- Regression models enabling you to predict the value of a metric in the future are not available.
- Advanced time series functions are not available.
The solution would be richer if Graphite was used as the data source and Grafana for visualisation only. This would provide more aggregation functions and allows you to do things like subtract one time series from another. As an example of what this might provide, I have a dashboard (not covered in this blog post) displaying the buffer turnover ratio and buffer waits ratio over an arbitrary moving window irrespective of when onstat -z was last run.
It is easy to confuse Graphite and Grafana, especially as both can be used independently, or Graphite can be a data source for Grafana.
As this is an Informix blog I ought to explain why I am using InfluxDB and not Informix time series? The simple answer is that to use Informix time series with Grafana properly someone would have to write and maintain a data source plugin for it like the one for InfluxDB we’ll be using. Doing so would give something more feature rich than InfluxDB for sure but perhaps not much more powerful than a Graphite/Grafana combination.
What to monitor
Potentially anything we can put a value to every ten seconds can be collected and stored in InfluxDB (which is a statement you can make about time series collections in general). For Linux operating system metrics there is a well-established collection daemon called collectd and, if I had better C programming skills, I could a collectd plugin for Informix.
For Informix systems the most obvious source is the system monitoring interface (SMI) which is the presentation of information held in shared memory through pseudo-tables in the sysmaster database. This covers the vast majority of what can be collected using onstat but is easier to handle in a programming language. Doing it this way means we can also collect real table data in the same manner.
For example the system profile or onstat -p can be captured with the following SQL:
SELECT
TRIM(name) AS name,
value
FROM
sysmaster:sysprofile
WHERE
name IN ('dskreads', 'bufreads', 'dskwrites', 'bufwrites', 'isamtot', 'isopens', 'isstarts', 'isreads', 'iswrites', 'isrewrites', 'isdeletes', 'iscommits', 'isrollbacks', 'latchwts', 'buffwts', 'lockreqs', 'lockwts', 'ckptwts', 'deadlks', 'lktouts', 'numckpts', 'plgpagewrites', 'plgwrites', 'llgrecs', 'llgpagewrites', 'llgwrites', 'pagreads', 'pagwrites', 'flushes', 'compress', 'fgwrites', 'lruwrites', 'chunkwrites', 'btraidx', 'dpra', 'rapgs_used', 'seqscans', 'totalsorts', 'memsorts', 'disksorts', 'maxsortspace')
It’s important to understand that all of these metrics are what I’d term counters. That is they only increase over time (unless they get so large they run out of bits and wrap or a DBA runs onstat -z). It gets difficult to see on a graph the difference between, say, 2394472 and 2394483 and so it’s useful to calculate a delta over the ten second window. Some things you might collect are automatically suitable for graphing because they are gauges: an example of this is the number of threads in your ready queue at any given moment.
Implementation
Practical demonstration with Docker containers
Nothing better than an example you can try at home (or work!). In the implementation example I will be using the IBM Informix Developer Edition Docker container which, at time of writing, runs Debian 8 (jeesie) and a second Docker container for InfluxDB and Grafana. You’ll of course need Docker installed on your laptop or workstation for this to work.
What this demonstration is going to build will look like the above. A collector script will collect metrics from Informix at a regular interval and post the results to InfluxDB. You will be able to use your usual web browser to connect to Grafana and visualise the data. Sounds simple?
We’ll start by setting up the InfluxDB/Grafana Docker container which will be also be using on a (minimal) Debian installation. In a terminal run:
docker pull debian
docker run -it --name influx_grafana_monitoring -p 8086:8086 -p 3000:3000 --hostname grafserv -e "GF_SECURITY_ADMIN_PASSWORD=secret" debian
Your terminal should now be inside the Docker container and logged in as root. Run these commands to install some extra packages and then InfluxDB:
apt-get update
apt-get -y install curl gnupg apt-transport-https procps
curl -sL https://repos.influxdata.com/influxdb.key | apt-key add -
echo "deb https://repos.influxdata.com/debian jessie stable" | tee -a /etc/apt/sources.list
apt-get update
apt-get -y install influxdb
Next install Grafana in the container:
echo "deb https://packagecloud.io/grafana/stable/debian/ jessie main" | tee -a /etc/apt/sources.list
curl https://packagecloud.io/gpg.key | apt-key add -
apt-get update
apt-get -y install grafana
Start the both services inside the container:
/etc/init.d/influxdb start
/etc/init.d/grafana-server start
We need to create an Influx database to store our time series data and we can do this with a REST API call:
curl -i -XPOST http://localhost:8086/query --data-urlencode "q=CREATE DATABASE informix"
If it works you should see a HTTP/1.1 200 OK response.
You should now be able to access the Grafana server running in your Docker container from your usual web browser at http://localhost:3000/
Log in with the user name admin and the password secret. Once logged in click Add data source and fill in the settings as follows (some of them are case-sensitive):
- Name
- informix
- Type
- InfluxDB
HTTP settings
- URL
- http://localhost:8086
- Access
- direct
HTTP Auth
- Basic auth
- Leave unticked
- With credentials
- Leave unticked
InfluxDB Details
- Database
- informix
- User
- Leave blank
- Password
- Leave blank
- Min time interval
- Leave at 10s
All being well you should see Data source is working in a big green box.
Now we are going to set up the Informix container to monitor. On your workstation in another terminal run:
$ docker pull ibmcom/informix-developer-database
docker run -it --name iif_developer_edition --privileged -p 9088:9088 -p 9089:9089 -p 27017:27017 -p 27018:27018 -p 27883:27883 --hostname ifxserver -e LICENSE=accept ibmcom/informix-developer-database:latest
The command above should provide a running Informix instance which may take a few moments after which control is passed back to the terminal. We are now going to get the scripts that will send data to InfluxDB:
sudo -i
apt-get update
apt-get -y install git libdbi-perl libjson-perl libwww-curl-perl make gcc libtest-pod-perl
We need to get the Perl DBD::Informix package from CPAN which will download, compile, test and install it for us.
. /home/informix/ifx_dev.env
export DBI_DBNAME=sysmaster
export DBD_INFORMIX_DATABASE=sysmaster
export DBD_INFORMIX_USERNAME=informix
export DBD_INFORMIX_PASSWORD=in4mix
cpan
Enter ‘yes’ to configure as much as possible. In the CPAN console type the case-sensitive command:
install DBD::Informix
There is quite a lot that could go wrong in the CPAN console but it should work if you’re using the IBM Informix DE Docker container and follow the steps exactly. If you’re installing on RedHat Linux or a derivative the required RPM package names you use with yum install will all be different.
Type logout to exit the root shell. You should be logged in as user informix again. Leave this session for later.
Run on your local workstation (outside both Docker containers) in another terminal window:
git clone https://github.com/skybet/informix-helpers.git
This assumes you have git installed. There are two important files in the post_to_influxdb directory:
- informix_smi_influx_uploader
- informix_smi.json
You will need to edit informix_smi.json and change all references from mydatabase to the name of the user/application database you want to monitor. For the purposes of the blog post in this demo, we are just going to monitor the sysmaster database so change all mydatabase references to sysmaster.
You can copy the files to your Informix Docker container as follows. To get the name of your Informix Docker container (not its hostname) simply type docker ps on your workstation.
$ docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
5a9c73712429 debian "bash" 8 minutes ago Up 8 minutes 0.0.0.0:3000->3000/tcp, 0.0.0.0:8086->8086/tcp influx_grafana_monitoring
e1c178b57164 ibmcom/informix-developer-database:latest "/bin/bash informi..." 13 minutes ago Up 13 minutes 0.0.0.0:9088-9089->9088-9089/tcp, 0.0.0.0:27017-27018->27017-27018/tcp, 0.0.0.0:27883->27883/tcp iif_developer_edition
From the above my Informix container name is e1c178b57164
docker cp informix_smi_influx_uploader e1c178b57164:/home/informix
docker cp informix_smi.json e1c178b57164:/home/informix
We should be ready to start collecting metrics and posting them to InfluxDB. Run in the Informix container as user informix:
cd
./informix_smi_influx_uploader -c ./informix_smi.json -i 10 -u http://other_container_ip:8086/write?db=informix
Change other_container_ip to the IP address of your InfluxDB/Grafana container. You must use the IP address unless you have name resolution which this basic Docker set up does not. If you don’t know what this is you can ping the docker container name from inside the InfluxDB/Grafana container using a command like ping -c 1 grafserv
All being well the Perl script should run continuously and collect and post data to InfluxDB every 10 seconds or whatever interval you specified with the -i switch.
To see anything in Grafana we’ll need to set up a dashboard. The file informix_server.json in the grafana_dashboard directory describes a Grafana dashboard. You’ll need to edit it a bit first and change all occurrences of the following:
- <%= @hostname %>
- hostname of your Informix docker container, normally the unqualified hostname of your Informix server
- <%= @informixserver %>
- Name of your Informix instance, dev
In the Grafana web browser click the Grafana logo and then Dashboards. Click Import. At Import Dashboard click Upload .json File. Hey presto, you should have a dashboard with graphs. Some may not display any data, e.g. Temporary dbspace usage, because there are no temporary dbspaces in the development Docker image by default.
Making this ready for production
There are a few bits I’ll leave to you for any production implementation:
- The collection shouldn’t run as user informix. Create a user for the monitoring and give it just the CONNECT and SELECT privileges it needs.
- You’ll also need to write a script to start/stop the collection with the instance.
- Linux operating system statistics, gathered through collectd would complement the dashboard very nicely.
- You’ll probably want to customise both the JSON file containing the SMI queries and the one describing the dashboard. You could add application metrics than can be collected from the database or create multiple dashboards especially if you don’t like the idea of one big one showing everything. Bear in mind any queries you write need to be fast and will run every 10 seconds.
- In the dashboard you may need to add/remove different page sizes to/from the buffer, page and disk reads/writes graphs.
Conclusion
It can be very useful to track virtual segment and temp. space usage on your server and correlate with events like update stats, ontape/onbar backups or application activity. You can use other tools to do this but these often are not as accessible or are purely in the realm of the DBA. A Grafana dashboard like the one described here should be very useful for you and colleagues, especially if they have their own dashboards on the same system which allow you to view your systems as a whole, and it might go some distance to demystifying Informix in your organisation.
Improving remote query performance by tuning FET_BUF_SIZE
Posted: 3 April, 2017 Filed under: SQL query tuning Leave a commentI thought I’d write blog post as a nice example of where tuning the client-side variable, FET_BUF_SIZE, really speeded up a remote query.
FET_BUF_SIZE is documented by IBM in the context of a Java application using JDBC here and as a server environment variable here.
One thing the documentation warns about is that simply setting this to a high value may degrade performance, especially if you have a lot of connections. With that in mind here are some facts about the query I’m running and using as a basis for these tests:
- I am just using a single connection to the database.
- the query returns around 10000 rows and 60 Mb of data.
- the client and the server are geographically separated from each other and Art Kagel’s dbping utility typically takes around 0.1 seconds to connect remotely; this compares with around 3 milliseconds locally.
- crucially the query runs in seconds locally on the server but takes over three minutes when run remotely.
If I begin running the query with the default value of FET_BUF_SIZE and monitor waits on the server, I can see that reads only go up slowly and that my session is waiting on a condition (indicated by the Y in position one of column two) more or less all the time:
> while [ 1 ] ; do
> onstat -u | grep thompson
> sleep 1
> done
Userthreads
address flags sessid user tty wait tout locks nreads nwrites
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 552 0
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 552 0
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 560 0
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 560 0
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 568 0
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 576 0
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 592 0
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 624 0
26eb492d18 Y--P-R- 76228 thompson 0 26e67cd298 0 0 624 0
The sixth column shows the rstcb value of the thread I’m waiting on. I can use onstat -g con (print conditions with waiters) to see that I’m waiting on the network:
> onstat -g con | grep -E '^cid|26e67cd298'
cid addr name waiter waittime
5789 26e67cd298 netnorm 84353 0
A quick check with onstat -g ses 76228 shows that thread id. 84353 does indeed correspond to my session.
While the wait time shown above is not increasing it’s a different story when we look at netstat, again on the server:
> netstat -nc | grep '172.16.0.1'
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 1312 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1284 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1306 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1302 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1194 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1206 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1266 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1304 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1318 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
tcp 0 1248 10.0.0.1:9088 172.16.0.1:37004 ESTABLISHED
What the above is showing us is that there are consistently around 1200 to 1300 bytes in the send queue (Send-Q). This is surely our bottleneck.
At this point when investigating the problem I considered modifying other parameters such as OPTOFC and Linux kernel parameters. However with a few moment’s thought it was clear these weren’t going to gain anything: OPTOFC optimises the open-fetch-close sequence and for a single long running query this is not going to give us anything measurable; and an investigation into increasing the Linux kernel parameter related to the send queue size was dismissed when we found that 1300 bytes was well below the maximum allowed.
In Informix 11.50 the maximum value of FET_BUF_SIZE is 32767 (32 kb) but this is increased to 2147483648, or as we’ll see actually 2147483647, (2 Gb) in 11.70 and above. We can therefore move onto to experiment with different values:
| FET_BUF_SIZE | Query run time (s) | Average Send-Q size over 10 samples | Maximum Send-Q size observed |
|---|---|---|---|
| Default | 221.2 | 1274 | 1332 |
| 1024 | 221.1 | 1255 | 1326 |
| 2048 | 221.1 | 1285 | 1338 |
| 4096 | 221.2 | 1297 | 1360 |
| 6144 | 102.1 | 2564 | 2676 |
| 8192 | 56.6 | 5031 | 5210 |
| 16384 | 22.6 | 12490 | 13054 |
| 32767 (max. 11.50 value) | 11.5 | 24665 | 29968 |
| 65536 | 7.0 | 62188 | 62612 |
| 131072 | 4.9 | 115793 | 127826 |
| 262144 | 4.0 | 146686 | 237568 |
| 524288 | 3.5 | 184320 | 249856 |
| 1048576 | 3.3 | 245760 | 473616 |
| 2097152 | 3.2 | 249856 | 486352 |
| 2147483647 (max. value – 1) | 3.0 | 245760 | 549352 |
| 2147483648 (supposed max. value) | 221.3 | 1276 | 1366 |
As the run times get shorter it gets tricky to measure the Send-Q using netstat -nc: it can be sampled very frequently using a command like:
while [ 1 ] ; do
netstat -n | grep '172.16.0.1'
done
This will produce many measurements per second and with this it’s possible to see it fill up and drain several times in the period while the statement is running.
It’s also interesting to play around with the boundaries. For example, with a FET_BUF_SIZE between around 5500 and 5600 maximum Send-Q sizes the same as those consistently achieved with a FET_BUF_SIZE of 6144 begin to creep into the results but many measurements remain around the values consistently measured wit a FET_BUF_SIZE of 4096:
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State
tcp 0 1316 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 1318 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 1278 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 1352 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 1288 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 2546 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 1278 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 2502 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 1266 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 1314 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 2506 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
tcp 0 1292 10.0.0.1:9088 172.16.0.1:37488 ESTABLISHED
So what are the conclusions?
- Increasing FET_BUF_SIZE at the client side can dramatically improve the speed of remote queries.
- Maximum Send-Q sizes, as measured by netstat, increase in discrete steps as FET_BUF_SIZE is increased.
- A larger Send-Q allows more data to be cached and reduces waits seen in Informix.
- To see any improvement at all FET_BUF_SIZE must be increased to at least 6000 (approximate value).
- Around boundaries between maximum Send-Q sizes there appears to be a cross-over region where maximum send queue sizes overlap from two adjacent values are seen from one second to the next.
- The maximum value allowed in 11.70 at least is 2147483647 and not 2147483648, as indicated in the documentation.
- The maximum 11.50 value of 32767 produced a run time nearly 4x slower than an optimised value for 11.70+
- Other testing I did, not documented here, shows that the results are uniform across JDBC and ESQL/C applications.
Note: all user names, IP addresses and port numbers used in this post have been altered.
