Why MySQL (and other DBs as well) indexes/keys are good!

I was working with a managed customer who handles their own DBA tasks on their servers when I noticed a recent change had created a major slow down in the speed of their front page. Here is the Apache Bench of their main page (actual URL removed to protect the guilty).

Server Software:        Apache/2.2.0
Server Hostname:        <REMOVED>
Document Path:          /index.php
Document Length:        103866 bytes
Concurrency Level:      10
Time taken for tests:   46.619197 seconds
Complete requests:      100
Failed requests:        0
Write errors:           0
Total transferred:      10454000 bytes
HTML transferred:       10386600 bytes
Requests per second:    2.15 [#/sec] (mean)
Time per request:       4661.920 [ms] (mean)
Time per request:       466.192 [ms] (mean, across all concurrent requests)
Transfer rate:          218.97 [Kbytes/sec] received

The power of a simple index:
CREATE INDEX phpsession_speed on session_data(phpsessionid);

Server Software:        Apache/2.2.0
Server Hostname:        <REMOVED>
Server Port:            80
Document Path:          /index.php
Document Length:        103866 bytes
Concurrency Level:      10
Time taken for tests:   3.396604 seconds
Complete requests:      100
Failed requests:        0
Write errors:           0
Total transferred:      10454000 bytes
HTML transferred:       10386600 bytes
Requests per second:    29.44 [#/sec] (mean)
Time per request:       339.660 [ms] (mean)
Time per request:       33.966 [ms] (mean, across all concurrent requests)
Transfer rate:          3005.35 [Kbytes/sec] received

There are MANY more optimizations I need to work with their DBA/Webdev because now their SQL server is saturating a gigabit connection with the webserver at the 30-40 RPS mark but this fixed their immediate problem.

Yet another cool use for SSDs

I did a test for a SSD as a external journal for a ext3 based single SCSI drive with some mildly interesting results ! I was going to rerun with a larger test size but ran out of time. If anyone re-runs this test and can send me the results I would like to see them.

(remove old journal)
tune2fs -O ^has_journal /dev/sdc1
(add new journal a 400M parition on a SSD)
mke2fs -b 4096 -O journal_dev -J device=/dev/sdk1,size=400 /dev/sdk1
tune2fs -j -J device=/dev/sdk1,size=400 /dev/sdc1

All tests done on a Dual Xeon 2.8Ghz (HT enabled) 800FSB 1M cache
Benchmarks used :

tiobench (from RPMForge) run from CLI with defaults `tiobench`
dd : ` dd if=/dev/zero of=/mnt/test.tmp bs=256k count=10000`

Results

400 MB SSD journal
DD: (2.6 GB) copied, 51.3763 seconds, 51.0 MB/s
Sequential Reads
2.6.18-194.el5                2000  4096    1  ###### 99.94%     0.003        0.13   0.00000  0.00000  1211
2.6.18-194.el5                2000  4096    2  ###### 399.0%     0.004        0.25   0.00000  0.00000   518
2.6.18-194.el5                2000  4096    4  ###### 1545.%     0.006       34.99   0.00000  0.00000   151
2.6.18-194.el5                2000  4096    8  ###### 3038.%     0.012      140.04   0.00000  0.00000    77
Random Reads
2.6.18-194.el5                2000  4096    1  836.90 96.41%     0.004        0.03   0.00000  0.00000   868
2.6.18-194.el5                2000  4096    2  ###### 370.3%     0.004        0.03   0.00000  0.00000   434
2.6.18-194.el5                2000  4096    4  ###### 1405.%     0.006        0.41   0.00000  0.00000   140
2.6.18-194.el5                2000  4096    8  ###### 779.5%     0.006        0.05   0.00000  0.00000   208
Sequential Writes
2.6.18-194.el5                2000  4096    1   43.03 23.59%     0.083     2692.94   0.00039  0.00000   182
2.6.18-194.el5                2000  4096    2   41.65 64.84%     0.170     2302.42   0.00078  0.00000    64
2.6.18-194.el5                2000  4096    4   41.87 219.0%     0.322     2970.18   0.00176  0.00000    19
2.6.18-194.el5                2000  4096    8   40.39 422.4%     0.667     3098.38   0.01211  0.00000    10
Random Writes
2.6.18-194.el5                2000  4096    1   14.72 5.746%     0.008        0.03   0.00000  0.00000   256
2.6.18-194.el5                2000  4096    2   14.63 16.48%     0.011        0.05   0.00000  0.00000    89
2.6.18-194.el5                2000  4096    4   56.14 103.4%     0.019       16.04   0.00000  0.00000    54
2.6.18-194.el5                2000  4096    8   40.74 161.6%     0.023       11.21   0.00000  0.00000    25
Default Journal on same disk
DD: (2.6 GB) copied, 100.868 seconds, 26.0 MB/s
Sequential Reads
2.6.18-194.el5                2000  4096    1  ###### 99.85%     0.003        1.80   0.00000  0.00000  1184
2.6.18-194.el5                2000  4096    2  ###### 397.9%     0.004        1.64   0.00000  0.00000   522
2.6.18-194.el5                2000  4096    4  ###### 1590.%     0.006        0.22   0.00000  0.00000   147
2.6.18-194.el5                2000  4096    8  ###### 2807.%     0.011      430.45   0.00000  0.00000    84
Random Reads
2.6.18-194.el5                2000  4096    1  840.96 96.87%     0.004        0.02   0.00000  0.00000   868
2.6.18-194.el5                2000  4096    2  ###### 370.3%     0.004        0.03   0.00000  0.00000   434
2.6.18-194.el5                2000  4096    4  ###### 1382.%     0.006        0.69   0.00000  0.00000   138
2.6.18-194.el5                2000  4096    8  ###### 1339.%     0.007        4.06   0.00000  0.00000   145
Sequential Writes
2.6.18-194.el5                2000  4096    1   23.28 13.37%     0.164     1449.18   0.00000  0.00000   174
2.6.18-194.el5                2000  4096    2   23.16 37.65%     0.330     1522.12   0.00000  0.00000    61
2.6.18-194.el5                2000  4096    4   21.45 125.1%     0.706     1493.51   0.00000  0.00000    17
2.6.18-194.el5                2000  4096    8   21.07 236.6%     1.419     1943.53   0.00000  0.00000     9
Random Writes
2.6.18-194.el5                2000  4096    1   15.15 4.749%     0.008        0.03   0.00000  0.00000   319
2.6.18-194.el5                2000  4096    2   15.22 14.60%     0.011        0.06   0.00000  0.00000   104
2.6.18-194.el5                2000  4096    4   44.56 101.8%     0.020        0.08   0.00000  0.00000    44
2.6.18-194.el5                2000  4096    8   21.06 73.30%     0.018        0.28   0.00000  0.00000    29

Spammers adopt Facebook headers ?

I saw these yet again today on a spam that found its way into a spam trap I have.

X-Priority: 3
X-Mailer: ZuckMail [version 1.00]
X-Facebook-Notify: password_reset; mailid=
Errors-To: terrace45@rotortug.com
X-FACEBOOK-PRIORITY: 1
MIME-Version: 1.0

The offending sender is (91.90.12.239) which , surprise surprise, isn’t a Facebook IP. I am working on a Spamassassin rule for this if anyone wants a “beta” copy of the meta rule let me know.

Ok I tested it and it appears to be working. The last 24 hours have seen over 100 hits all obvious spam (total volume during that time was 564K). The meta rule I am using is:

header CS_881                   X-Mailer =~ /\bZuckMail\b/i
header CS_882                   Received !~ /\bfacebook.com\b/i
meta FAKEFACEBOOK_01            (CS_881 && CS_882)
score FAKEFACEBOOK_01           3.9

Change the header names,meta names, and score to reflect what you feel is best for your system.

Google Wifi blunder or wake up call ?

Love it or hate it google has around 600GB or captured wifi data  ! I do not want to get into war of opinions about this but I do think this should be a wake up call for everyone using wireless who has not secured their network to do so.

If you dont know how to do this find a family member, neighbor, Nerd Herd person, Google search,  or whoever to do it for you (even if it costs money). Aside from keeping your neighbors “out of your bushes” it will help keep your data safe from random war  Google driving.

Star Trek, Linux, and BoFH MoTD

If you do a :

telnet misterx.org 1701

You can get several MoTDs and some info on Star Trek online. Why did I do this..who knows…I was bored one night waiting for a FS benchmark to finish. Heck I dont even play Star Trek online I just was playing with a way to parse content in a bash script.

This totally geeky waste of time is brought to you thanks to : Steam, lynx, DJB (TCPSERVER+DAEMONTOOLS), and IMDB.com!

RHEL 6 Beta ..I finally am finding the time!

[root@localhost ~]# cat /etc/redhat-release
Red Hat Enterprise Linux Server release 6.0 Beta (Santiago)

LET THE FLOGGINGS (benchmarks) BEGIN!

Update: Appears the project iotop that I have been eyeing for sometime is now a option in the standard install. This is very nice I hope they choose some of the other system tools (like updated dstat, atop, and htop) to add as well.

Update: Ran a ps finally (I know I am slow getting to these kind of important things these days) and I noticed sendmail is gone ! Oh my now thats a change for the better. After 12 years of living with it as the default mailer I am excited to get to know postfix ! I have run it before in the past but 12 years running Qmail doesnt leave one much time to play around with other mailers. I am not biased I think the top two MTAs are Qmail and Postfix so I cant complain about the choice.

Atoms vs GlusterFS (and why I like MSI-X)

Well I am in the process of testing clusterFS solutions for work and figured it would also be a great chance to put our Atom product (SuperMicro’s 5015A-H) through the paces. During the testing phase, as seen here, I found that tests would need more horsepower to really be worthwhile.

I did find out that the Atoms can do about 36MBs a second using Replicated GlusterFS with caching tweaks before the processor max out. On my newer MSI-X systems the Ethernet load would have been pushed around several (or all) cores but since the Atoms only have MSI capabilities on their NICs I watched as one CPU pegged and other other one sat back and drank a Mojito. I was almost tempted into firing up a few high CPU tasks and using ole taskset to make the other CPU suffer but I refrained.

I will be updating once I can get a more powerful test setup going.

Apache achieves Leet-ness

Was troubleshooting a coding issue for a customer the other day when I noticed the number of requests currently being processed. I am going to write about this in the coming days. Basically there was a code issue (we do not support code for this customer) that caused a large number of “sleep” states in MySQL as well as a huge number of ‘W Sending Reply’ states in Apache.

Current Time: Thursday, 11-Feb-2010 11:47:54 CST
Restart Time: Thursday, 11-Feb-2010 09:17:12 CST
Parent Server Generation: 0
Server uptime: 2 hours 30 minutes 41 seconds
Total accesses: 226733 – Total Traffic: 10.8 GB
CPU Usage: u1812.56 s80.08 cu.04 cs0 – 20.9% CPU load
25.1 requests/sec – 1.2 MB/second – 49.8 kB/request
1337 requests currently being processed, 113 idle workers

5 Minute Disk I/O in KB

THIS IS LEGACY I HAVE REPLACED IT. I am leaving this up for archival purposes as it does still work just not as accurately as I would like.
OS: CentOS 5.4
Arch : x86_64
Version : 0.1a
Required Packages : netsnmpd, sysstat
snmpd conf addition:
exec .1.3.6.1.4.1.2021.40 SARDISKIO /usr/bin/mrtg_diskio
Client Script Used:
<script>
#!/bin/bash
#V 0.1b MisterX Dec 9th 2009
# Replace md0-md3 with the drives you want to watch
#OUTPUT example for first Drive :
#1.3.6.1.4.1.2021.40.101.1 tps
#1.3.6.1.4.1.2021.40.101.2 kB_read/s
#1.3.6.1.4.1.2021.40.1.1.3 kB_wrtn/s
#1.3.6.1.4.1.2021.40.101.4 kB_read
#1.3.6.1.4.1.2021.40.101.5 kB_wrtn
# and so on for each additional Drive. A snmpwalk -v2c -On -c $community $host 1.3.6.1.4.1.2021.40.101 will show
#you the full list for all drives.
for d in md0 md1 md2 md3; do

/usr/bin/iostat -dk | grep $d | awk '{print $2}';
/usr/bin/iostat -dk | grep $d | awk '{print $3}';
/usr/bin/iostat -dk | grep $d | awk '{print $4}';
/usr/bin/iostat -dk | grep $d | awk '{print $5}';
/usr/bin/iostat -dk | grep $d | awk '{print $6}';

done
</script>

MRTG Code :

<mrtg_config>
Target[$server_name-disk]: 1.3.6.1.4.1.2021.40.101.4&1.3.6.1.4.1.2021.40.101.5:$community@$remote_server
Title[$server_name-disk]:  Disk $drive 5 min Average I/O Utilization
MaxBytes[$server_name-disk]: 10240000000000000
PageTop[$server_name-disk]: <H1>5 min Avg. I/O Utilization Report</H1>
kmg[$server_name-disk]: KB,MB,GB
LegendI[$server_name-disk]: 5 min Avg. I/O KBread
LegendO[$server_name-disk]: 5 min Avg. I/O KBwrite
Legend1[$server_name-disk]: 5 min Avg. I/O KBread
Legend2[$server_name-disk]: 5 min Avg. I/O KBwrite
YLegend[$server_name-disk]: Kilobytes
ShortLegend[$server_name-disk]: &
Options[$server_name-disk]: growright,nopercent
</mrtg_config>

This is just a average to get a overview and will never replace good administration.
Its only to track trends and general issues but if you use MRTG you probably have other tools you use and already know this ;)

Debugging Apache segfault with strace

OS: CentOS 4.8
Apache : Custom RPM from source with only a single change to the location of the suexec directory

strace -t -f -v  -p $process -o /path/to/outputfile (note the $process is the primary Apache Process)

To find the primary Apache Process you do a :

ps -ef | grep httpd

and it returns something like this :

apache   26898 22378  8 13:50 ?        00:00:01 /usr/sbin/httpd -k start

the second number 22378 is the PID of the Apache parent process. I then waited for a :

Dec 11 10:02:20 web02 kernel: httpd[7121]: segfault at 0000007fbf3fff0c rip 0000002a9567344a rsp 0000007fbf3ffe90 error 6

in my /var/log/messages. Once that came I did a:

grep SIGSEGV /path/to/file_generated_w/strace

and noted times and PIDs. Here is a example output :

19730 12:07:35 — SIGSEGV (Segmentation fault) @ 0 (0) —
19784 12:08:56 — SIGSEGV (Segmentation fault) @ 0 (0) —

I then grepped out the PIDs (19784 and 19730 in the above example) with a segfault to different files and began reading. To grep this out I did :

grep 19730 /path/to/file_generated_w/strace > /tmp/out.19730

It was in these files I found my problem. Your mileage may vary but I found this method much easier than using the Apache config setting of CoreDumpDirectory which requires several changes that have to be undone. The CoreDumpDirectory setting also requires a few restarts of Apache which in a production environment can be undesired.

The main caveat to using strace is that , on a busy server, you can generate 100-300M of logs per minute so make sure you have the diskspace on the partition you are sending out strace output.