2

I have a strange problem...

My script:

#!/bin/bash
SECONDS=0

lock_file=/tmp/$0.lock

[ -e $lock_file ] && exit

touch $lock_file

echo "<<<db2_hadr_check>>>"
instances=( db2inst1 db2inst2 )

plog() {
        lfile=/tmp/$0.log

        echo "[`date +%T`] $1" >> $lfile
}

for instance in "${instances[@]}"; do
        plog "get dbname for instance $instance"
        name=$(su - $instance -c 'echo $dbname')
        plog "get hadr info for instance $instance"
        arr=($(su - $instance -c 'db2pd -db $dbname -hadr | egrep -i "HADR_CONNECT_STATUS |HADR_LOG_GAP" | cut -d "=" -f 2'))
        plog "check result for instance $instance"

        s=${arr[0]}
        lg=${arr[1]}

        [ -z $s ] && s="DISCONNECTED"
        [ -z $lg ] && lg=0

        plog "return result for instance $instance"

        #dbname hadr_conn_status log_gap
        echo "$name $s $lg"
done
plog "Execution time: $SECONDS"
plog "############################################################"
rm $lock_file

I manualy run this script on my test server (Fedora release 21)...

Log from my manual run:

[11:46:36] get dbname for instance db2inst1
[11:46:37] get hadr info for instance db2inst1
[11:46:37] check result for instance db2inst1
[11:46:37] return result for instance db2inst1
[11:46:37] get dbname for instance db2inst2
[11:46:38] get hadr info for instance db2inst2
[11:46:39] check result for instance db2inst2
[11:46:39] return result for instance db2inst2
[11:46:39] Execution time: 3
[11:46:39] ############################################################

After this, I added this check in my monitor server (nagios + check_mk). If I run check_mk_agent (which then call my script) I get this execution times:

real    0m2.923s
user    0m0.755s
sys     0m1.982s

This is OK.

Here is my problem...

Log from execution with check_mk server:

[11:48:38] get dbname for instance db2inst1
[11:49:04] get hadr info for instance db2inst1
[11:49:30] check result for instance db2inst1
[11:49:30] return result for instance db2inst1
[11:49:30] get dbname for instance db2inst2
[11:49:55] get hadr info for instance db2inst2
[11:50:21] check result for instance db2inst2
[11:50:21] return result for instance db2inst2
[11:50:21] Execution time: 103
[11:50:21] ############################################################

when this script is called from check_mk (nagios) it runs for 103 seconds!

Can someone explain that?


Additional info #1:

check_mk server use xinetd to execute check_mk_agent on host

config file (/etc/xinetd.d/check_mk):

service check_mk
{
        type           = UNLISTED
        port           = 6556
        socket_type    = stream
        protocol       = tcp
        wait           = no
        user           = root
        server         = /usr/bin/check_mk_agent

        log_on_success =

        disable        = no
}

/etc/pam.d/su:

#%PAM-1.0
auth            sufficient      pam_rootok.so
# Uncomment the following line to implicitly trust users in the "wheel" group.
#auth           sufficient      pam_wheel.so trust use_uid
# Uncomment the following line to require a user to be in the "wheel" group.
#auth           required        pam_wheel.so use_uid
auth            substack        system-auth
auth            include         postlogin
account         sufficient      pam_succeed_if.so uid = 0 use_uid quiet
account         include         system-auth
password        include         system-auth
session         include         system-auth
session         include         postlogin
session         optional        pam_xauth.so

Additional info #2:

After @Lambert comment I did this:

On nagios server in /etc/hosts I added db2 server IP On db2 server /etc/hosts I added nagios server IP

I tried 2 more things:

On nagios server:

Command:

time ssh root@db2server /usr/bin/check_mk_agent

Result:

...

real    0m5.917s
user    0m0.025s
sys     0m0.028s

Command:

time telnet db2server 6556

Result:

...

real    0m51.859s
user    0m0.005s
sys     0m0.014s

I ran this multiple times with the same results...

On db2server in /var/log/messages I found this:

Oct 30 14:48:55 db2server su: (to db2inst1) root on pts/0 <- 1. command
Oct 30 14:50:59 db2server su: (to db2inst1) root on none  <- 2. command

Additional info #3:

Command:

time ssh root@db2server telnet localhost 6556

Result:

real    0m7.510s
user    0m0.029s
sys     0m0.034s

Any ideas?

  • 1
    seems that each su - $instance... is taking ~25 seconds when nagios calls it; is your su configured to do some extra logging or lookups? cat /etc/pam.d/su to see what's configured... – Jeff Schaller Oct 29 '15 at 14:05
  • @jeffschaller I add /etc/pam.d/su config file... do you see something strange in it? – Wolfy Oct 29 '15 at 14:37
  • maybe its waiting for a password. why do you quote some expansions and not other expansions? – mikeserv Oct 29 '15 at 17:01
  • @mikeserv if it wait for a password it won't give me any result after 100s, but except for time difference is all the same. This is the only expansion... – Wolfy Oct 29 '15 at 18:42
  • What happens when you call the check directly from nagios using a terminal session (ie. check_nrpe or check_mk) twice, right after eachother. Is the second run faster than the first run? If the second run is much faster, the issue is probably name resolving because the host record is coming from the client cache during the second run. Try to add the nagios host to the /etc/hosts file. – Lambert Oct 29 '15 at 19:25

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.