Bug 1031147

Description of problem:

The 'started' message gets written to the screen (when starting JBoss via RPM), but JBoss is not yet completely started. 

Examples: 

        # date; service jbossas restart; date;
        Fri Nov 15 08:56:44 MST 2013
        Stopping jbossas:                                          [  OK  ]
        Starting jbossas:                                          [  OK  ]
        Fri Nov 15 08:56:57 MST 2013
        # grep -i "Started in" /var/log/jbossas/standalone/console.log
        08:57:07,620 INFO  [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.1.1.GA (AS 7.2.1.Final-redhat-10) started in 10144ms - 
            Started 123 of 177 services (53 services are passive or on-demand)

        # date; service jbossas restart; date; grep -q 'JBoss EAP 6.*started in' /var/log/jbossas/standalone/console.log > /dev/null 2>&1 ; echo $?
        Fri Nov 15 09:09:31 MST 2013
        Stopping jbossas:                                          [  OK  ]
        Starting jbossas:                                          [  OK  ]
        Fri Nov 15 09:09:44 MST 2013
        1

        # date; service jbossas restart; date; netstat -tunap | grep LISTEN
        Fri Nov 15 09:32:45 MST 2013
        Stopping jbossas:                                          [  OK  ]
        Starting jbossas:                                          [  OK  ]
        Fri Nov 15 09:32:58 MST 2013
        tcp        0      0 0.0.0.0:111                 0.0.0.0:*                   LISTEN      1288/rpcbind        
        tcp        0      0 0.0.0.0:22                  0.0.0.0:*                   LISTEN      4840/sshd           
        tcp        0      0 127.0.0.1:631               0.0.0.0:*                   LISTEN      4713/cupsd          
        tcp        0      0 127.0.0.1:25                0.0.0.0:*                   LISTEN      4916/master         
        tcp        0      0 0.0.0.0:48513               0.0.0.0:*                   LISTEN      1306/rpc.statd      
        tcp        0      0 :::111                      :::*                        LISTEN      1288/rpcbind        
        tcp        0      0 :::22                       :::*                        LISTEN      4840/sshd           
        tcp        0      0 ::1:631                     :::*                        LISTEN      4713/cupsd          
        tcp        0      0 ::1:25                      :::*                        LISTEN      4916/master         
        tcp        0      0 :::43494                    :::*                        LISTEN      1306/rpc.statd  

It looks like the following is not acting as it should. 

        count=0
        launched=false

        until [ $count -gt $JBOSS_STARTUP_WAIT ]
        do
          grep -q 'JBoss EAP 6.*started in' $JBOSS_CONSOLE_LOG > /dev/null 2>&1
          if [ $? -eq 0 ] ; then
            launched=true
            success "${NAME} startup"
            echo
            break
          fi
          sleep 10
          let count=$count+10;
        done

Specifically the 'grep -q 'JBoss EAP 6.*started in' $JBOSS_CONSOLE_LOG > /dev/null 2>&1' command, does not seem to be working correctly. 

How reproducible:

# date; service jbossas restart; date; grep -q 'JBoss EAP 6.*started in' /var/log/jbossas/standalone/console.log > /dev/null 2>&1 ; echo $?


Actual results:

The grep fails, this seems to greping an existing file (of the console.log) and getting a valid return status. This seems to be cause by the following code: 

    # determine userid to start jboss
    if [ -z "$SUBIT" ]; then
        eval $CMD_START >>${JBOSS_CONSOLE_LOG} 2>&1 &
    else
        $SUBIT "export JAVA_HOME=$JAVA_HOME; export JAVA_OPTS=\"$JAVA_OPTS\";$CMD_START >${JBOSS_CONSOLE_LOG} 2>&1 &"
    fi

The key issue here is that (the following command), seems to go to the back ground, and not enough time passes in the scrip before the script is overwritten. 

$SUBIT "export JAVA_HOME=$JAVA_HOME; export JAVA_OPTS=\"$JAVA_OPTS\";$CMD_START >${JBOSS_CONSOLE_LOG} 2>&1 &"

Because this process is backgrounded (threaded) the subsequent check to see if JBoss is running check the existing JBOSS_CONSOLE_LOG file. 

Expected results:

This should take some time to complete (10 - 20 seconds), and JBoss report that JBoss has started (correctly) or report that jboss's startup has timed out.

Additional info:

To fix this, the following should be added to the init script for the rpms.

254a255,257
        >         if [ -e $JBOSS_CONSOLE_LOG ]; then
        >              rm -f $JBOSS_CONSOLE_LOG
        >         fi