13 Replies Latest reply on Sep 13, 2013 2:50 AM by jaikiran

Wildfly : Poor Performance JNDI lookup

ismsteve Sep 11, 2013 4:13 PM

In My Ejb Client in Jboss 4.23 My Code looks like this

Long start = System.currentTimeMillis();

// Test Connection

facade = (PWFacade) context.lookup("pworks/PWFacadeBean/remote");

System.out.println("Lookup took "+(System.currentTimeMillis() - start));

=============================================================

Result: Lookup took 224

=============================================================

I upgrade to WildFLY

Code:

Long start = System.currentTimeMillis();

// Test Connection

facade = (PWFacade) context.lookup("ejb:pworks/business/PWFacadeBean!com.ai.pworks.session.interfaces.PWFacade?stateful");

System.out.println("Lookup took "+(System.currentTimeMillis() - start));

=============================================================

Result: Lookup took 7389

=============================================================

It took 7 additional seconds just to do the lookup.

My EJB Client is a standalone Swing client and does not reside on the server

The Client log has the following output:

2013-09-11 16:11:24,476 INFO [org.jboss.ejb.client] JBoss EJB Client version 2.0.0.Beta3

2013-09-11 16:11:31,707 INFO [org.jboss.ejb.client.remoting] EJBCLIENT000017: Received server version 2 and marshalling strategies [river]

As you can see there is Approx 7 seconds between the printouts. This may provide a clue as to where the bottle neck is occurring.

1. Re: Wildfly : Poor Performance JNDI lookup

smarlow Sep 11, 2013 7:18 PM (in response to ismsteve)

I wonder if we are waiting for a resource to be ready (still starting up the app server or something like that).

Is this right after starting the WildFly application server? What happens when you run the test again a few times? Same 7 seconds?

What happens if you change the code to loop a 10 times or so. On each loop iteration, time the lookup and print the duration of each lookup.

Scott
Actions
2. Re: Wildfly : Poor Performance JNDI lookup

jaikiran Sep 12, 2013 1:48 AM (in response to ismsteve)

What does the jboss-ejb-client.properties or the properties that you pass to InitialContext look like? I think you might have listed certain connections in there which might be timing out.
Actions
3. Re: Wildfly : Poor Performance JNDI lookup

ctomc Sep 12, 2013 5:40 AM (in response to ismsteve)

Is this local remote call or is machine on different computer?
Actions
4. Re: Wildfly : Poor Performance JNDI lookup

ismsteve Sep 12, 2013 10:34 AM (in response to smarlow)

Scott Marlow wrote:

I wonder if we are waiting for a resource to be ready (still starting up the app server or something like that).

Is this right after starting the WildFly application server? What happens when you run the test again a few times? Same 7 seconds?

What happens if you change the code to loop a 10 times or so. On each loop iteration, time the lookup and print the duration of each lookup.

Scott

Hi Scott,
I tried it several times after the server started and got the same performance.
I put it in a loop and here are the results:
================================================
Attempt # 1
Lookup took 7032ms
Attempt # 2
Lookup took 9ms
Attempt # 3
Lookup took 7ms
Attempt # 4
Lookup took 8ms
Attempt # 5
Lookup took 7ms
Attempt # 6
Lookup took 7ms
Attempt # 7
Lookup took 8ms
Attempt # 8
Lookup took 7ms
Attempt # 9
Lookup took 8ms
Attempt # 10
Lookup took 7ms
Actions
5. Re: Wildfly : Poor Performance JNDI lookup

smarlow Sep 12, 2013 10:54 AM (in response to ismsteve)
Interesting, so the first invocation took seven seconds and the others all took less then ten milliseconds. Sounds to me like something is either still loading or some type of lazy loading is going on.

Do you have answers to post for other questions yet (number of machines involved and properties)? Sorry that the forums software is giving you trouble but this is better than IRC (IMO).

Additional questions:

Does it make a difference if you wait a minute after starting the app server, before starting the test?
Do you see any server.log (or console) output after the test is started, that could indicate that something finished loading/initializing after the test started?
Actions
6. Re: Wildfly : Poor Performance JNDI lookup

ismsteve Sep 12, 2013 11:01 AM (in response to ismsteve)
========================================================================================================
Code
========================================================================================================
    public PWSession(String username, String password, String serverIp, String serverPort) throwsCommunicationException, EJBAccessException, NameNotFoundException, NamingException, Exception {
        /**
        * Create connection to jboss Server passing in the user credentials
        */
        this.username = username;
        this.password = password;
        this.serverIp = serverIp;
        this.serverPort = serverPort;
        final EJBClientConfiguration clientConfiguration = new PropertiesBasedEJBClientConfiguration(
                createClientConfigurationProperties(username, password, serverIp, serverPort));
        // create a context selectorintln("#2");
        ContextSelector<EJBClientContext> contextSelector = null;
        try {
            contextSelector = new ConfigBasedEJBClientContextSelector(clientConfiguration);
        } catch (Exception e) {
            e.printStackTrace();
        }

        EJBClientContext.setSelector(contextSelector);
        try {
            java.util.Hashtable ht = new java.util.Hashtable();
            ht.put("jboss.naming.client.ejb.context", true);
            ht.put(Context.URL_PKG_PREFIXES, "org.jboss.ejb.client.naming");
            context = new InitialContext(ht);
                   while (x < 10){
                   Long start = System.currentTimeMillis();
                // Test Connection
                  System.out.println("Attempt # "+(++x));
                 facade = (PWFacade) context.lookup("ejb:pworks/business/PWFacadeBean!com.ai.pworks.session.interfaces.PWFacade?stateful");
                 System.out.println("Lookup took "+(System.currentTimeMillis() - start)+"ms");
            }
        } catch (Exception e) {
            System.out.println("Error Occurred");
            e.printStackTrace();
        }
    }

    private static Properties createClientConfigurationProperties(String userName, String password, StringserverIp, String serverPort) {
        final Properties properties = new Properties();
        properties.put("remote.connectionprovider.create.options.org.xnio.Options.SSL_ENABLED", "false");
        properties.put("remote.connections", "default");
        properties.put("endpoint.name", "client-endpoint");
        properties.put("remote.connection.default.host", serverIp);
        properties.put("remote.connection.default.port", serverPort);
        properties.put("remote.connection.default.username", userName);
        properties.put("remote.connection.default.password", password);
               properties.put("remote.connection.default.connect.options.org.xnio.Options.SASL_POLICY_NOANONYMOUS", "true");
               properties.put("remote.connection.default.connect.options.org.xnio.Options.SASL_DISALLOWED_MECHANISMS","JBOSS-LOCAL-USER");
              properties.put("remote.connection.default.connect.options.org.xnio.Options.SASL_POLICY_NOPLAINTEXT", "false");
        return properties;
Actions
7. Re: Wildfly : Poor Performance JNDI lookup

ismsteve Sep 12, 2013 11:13 AM (in response to ismsteve)
Scott Marlow wrote:

Interesting, so the first invocation took seven seconds and the others all took less then ten milliseconds. Sounds to me like something is either still loading or some type of lazy loading is going on.

Do you have answers to post for other questions yet (number of machines involved and properties)? Sorry that the forums software is giving you trouble but this is better than IRC (IMO).

Additional questions:

Does it make a difference if you wait a minute after starting the app server, before starting the test?

Do you see any server.log (or console) output after the test is started, that could indicate that something finished loading/initializing after the test started?

Hey Scott,
1. No. The Server Has been up since yesterday and still the same issue.
2. The First thing I see on the server side(After the 7 seconds) Is:
11:06:04,858 TRACE [org.jboss.security] (DefaultQuartzScheduler_QuartzSchedulerThread) PBOX000200: Begin isValid, principal: null, cache entry: null
11:06:04,858 TRACE [org.jboss.security] (DefaultQuartzScheduler_QuartzSchedulerThread) PBOX000209: defaultLogin, principal: null
11:06:04,858 TRACE [org.jboss.security] (DefaultQuartzScheduler_QuartzSchedulerThread) PBOX000221: Begin getAppConfigurationEntry(EncryptPWPassword), size: 5
11:06:04,858 TRACE [org.jboss.security] (DefaultQuartzScheduler_QuartzSchedulerThread) PBOX000224: End getAppConfigurationEntry(EncryptPWPassword), AuthInfo: AppConfigurationEntry[]:
Actions
8. Re: Wildfly : Poor Performance JNDI lookup

smarlow Sep 12, 2013 11:44 AM (in response to ismsteve)

Can you also post the server side bean (source) that you are looking up?
Actions
9. Re: Wildfly : Poor Performance JNDI lookup

ismsteve Sep 12, 2013 11:51 AM (in response to smarlow)

=================================================
Stateful Bean
=================================================

@Stateful
public class PWFacadeBean implements PWFacade, Serializable {
    private static org.apache.log4j.Logger logger =
            org.apache.log4j.Logger.getLogger(PWFacadeBean.class.getName());
    private AppUser user;
    // Module Management Beans
    @EJB
    private AgreementMgmt agreementMgmt;
    @EJB
    private AvStatsMgmt avStatsMgmt;
    @EJB
    private BillingMgmt billingMgmt;
    @EJB
    private CaActTrackingMgmt caActTrackingMgmt;
    @EJB
    private AdminDataMgmt adminDataMgmt;
    @EJB
    private CashPostingMgmt cashPostingMgmt;
    @EJB
    private CompanyMgmt companyMgmt;
    @EJB
    private OraFinIfMgmt oraFinIfMgmt;
    @EJB
    private PsFinIfMgmt psFinIfMgmt;
    @EJB
    private PaymentsIfMgmt paymentsIfMgmt;
    @EJB
    private RevenueExpMgmt revenueExpMgmt;
    @EJB
    private RiskMgmt riskMgmt;
    //@EJB private RossFinIfMgmt rossFinIfMgmt;
    @EJB
    private SapFinIfMgmt sapFinIfMgmt;
    @EJB
    private RossFinIfMgmt rossFinIfMgmt;
    @EJB
    private SpaceMgmt spaceMgmt;
    //@EJB private TenantAltMgmt tenantAltMgmt;
    @EJB
    private UtilitiesMgmt utilitiesMgmt;
    @EJB
    private RevenueExpReportMgmt revenueExpReportMgmt;
    // Module Report Beans
    @EJB
    private AgreementReportMgmt agreementReport;
    @EJB
    private BillingReportMgmt billingReportMgmt;
    @EJB
    private CompanyReportMgmt companyReport;
    @EJB
    private ReportMgmt reportMgmt;
    @EJB
    private CashPostingReportMgmt cashPostingReportMgmt;
    @EJB
    private SysAdminReportMgmt sysAdminReportMgmt;
    @EJB
    private CatFimIfMgmt catFimIfMgmt;
    @EJB
    private CatExternalIfMgmt catExternalIfMgmt;
    // List of pending Reports
    private ArrayList<String> reportRequestIds;
    // Space Inventory Report Bean
    @EJB
    private SpaceReportMgmt spaceReportMgmt;
    @EJB
    private ViewerMgmt viewerMgmt;
    @EJB
    private RiskMgmtReportMgmt riskMgmtReportMgmt;
    @EJB
    private UtilitiesReportMgmt utilitiesReportMgmt;
    @EJB
    private CaActTrackingReportMgmt caActTrackingReportMgmt;
    @EJB
    private AvStatsReportMgmt avStatsReportMgmt;

    @PostConstruct
    public void init() {
        reportRequestIds = new ArrayList<String>();
        logger.info("Stateful FacadeBean loaded");
    }

    // Module Management Beans
    public AgreementMgmt getAgreementMgmt() {
        return agreementMgmt;
    }

    public AvStatsMgmt getAvStatsMgmt() {
        return avStatsMgmt;
    }

    public BillingMgmt getBillingMgmt() {
        return billingMgmt;
    }

    public CaActTrackingMgmt getCaActTrackingMgmt() {
        return caActTrackingMgmt;
    }

    public AdminDataMgmt getAdminDataMgmt() {
        return adminDataMgmt;
    }

    public CashPostingMgmt getCashPostingMgmt() {
        return cashPostingMgmt;
    }

    public CompanyMgmt getCompanyMgmt() {
        return companyMgmt;
    }

    public RevenueExpMgmt getRevenueExpMgmt() {
        return revenueExpMgmt;
    }

    public RiskMgmt getRiskMgmt() {
        return riskMgmt;
    }

    public SpaceMgmt getSpaceMgmt() {
        return spaceMgmt;
    }

    public UtilitiesMgmt getUtilitiesMgmt() {
        return utilitiesMgmt;
    }

    // Module Report Beans
    public AgreementReportMgmt getAgreementReport() {
        return agreementReport;
    }

    public BillingReportMgmt getBillingReportMgmt() {
        return billingReportMgmt;
    }

    public CashPostingReportMgmt getCashPostingReportMgmt() {
        return cashPostingReportMgmt;
    }

    public CompanyReportMgmt getCompanyReport() {
        return companyReport;
    }

    public ReportMgmt getReportMgmt() {
        return reportMgmt;
    }

    public SysAdminReportMgmt getSysAdminReportMgmt() {
        return sysAdminReportMgmt;
    }

    public int getReportRequestIdsSize() {
        return reportRequestIds.size();
    }

    /**
     * Public accessor for
     * <code>reportRequestIds</code>.
     *
     * @author jganoff
     */
    public ArrayList<String> getReportRequestIds() {
        return reportRequestIds;
    }

    /**
     * Add the
     * <code>reportRequestId</code> to the cache of Report Request Ids.
     *
     * @param reportRequestId The Report Request Id to add to the cache.
     *
     * @author jganoff
     */
    public void addReportRequestId(String reportRequestId) {
        reportRequestIds.add(reportRequestId);
    }

    /**
     * Determines if the
     * <code>reportRequestId</code> given is in the cache.
     *
     * @param reportRequestId Non-null Report Request Id to lookup.
     *
     * @return true - Report Request Id found in cache. false - Report Request
     * Id not found in cache.
     *
     * @author jganoff
     */
    public boolean lookupReportRequestId(String reportRequestId) {
        return reportRequestIds.contains(reportRequestId);
    }

    /**
     * Remove the
     * <code>reportRequestId</code> from the cache of Report Request Ids.
     *
     * @param reportRequestId Non-null Report Request Id to lookup.
     *
     * @return true - Removed successful. false - Remove unsuccessful.
     *
     * @author jganoff
     */
    public boolean removeReportRequestIdFromCache(String reportRequestId) {
        return reportRequestIds.remove(reportRequestId);
    }

    public SpaceReportMgmt getSpaceReportMgmt() {
        return spaceReportMgmt;
    }

    public ViewerMgmt getViewerMgmt() {
        return viewerMgmt;
    }

    public RiskMgmtReportMgmt getRiskMgmtReportMgmt() {
        return riskMgmtReportMgmt;
    }

    public UtilitiesReportMgmt getUtilitiesReportMgmt() {
        return utilitiesReportMgmt;
    }

    public CaActTrackingReportMgmt getCaActTrackingReportMgmt() {
        return caActTrackingReportMgmt;
    }

    public AvStatsReportMgmt getAvStatsReportMgmt() {
        return avStatsReportMgmt;
    }

    public OraFinIfMgmt getOraFinIfMgmt() {
        return oraFinIfMgmt;
    }

    public PsFinIfMgmt getPsFinIfMgmt() {
        return psFinIfMgmt;
    }

    public PaymentsIfMgmt getPaymentsIfMgmt() {
        return paymentsIfMgmt;
    }

    public RevenueExpReportMgmt getRevenueExpReportMgmt() {
        return revenueExpReportMgmt;
    }

    public SapFinIfMgmt getSapFinIfMgmt() {
        return sapFinIfMgmt;
    }

    public RossFinIfMgmt getRossFinIfMgmt() {
        return rossFinIfMgmt;
    }

    public CatFimIfMgmt getCatFimIfMgmt() {
        return catFimIfMgmt;
    }

    public CatExternalIfMgmt getCatExternalIfMgmt() {
        return catExternalIfMgmt;
    }
}

=================================================
Stateful Bean Interface
=================================================
import javax.ejb.Remote;

@Remote
public interface PWFacade {

public AgreementMgmt getAgreementMgmt();

public AvStatsMgmt getAvStatsMgmt();

public BillingMgmt getBillingMgmt();

public CaActTrackingMgmt getCaActTrackingMgmt();

public AdminDataMgmt getAdminDataMgmt();

public CashPostingMgmt getCashPostingMgmt();

public CompanyMgmt getCompanyMgmt();

public RevenueExpMgmt getRevenueExpMgmt();

public RevenueExpReportMgmt getRevenueExpReportMgmt();

public RiskMgmt getRiskMgmt();

public SpaceMgmt getSpaceMgmt();

public UtilitiesMgmt getUtilitiesMgmt();

public AgreementReportMgmt getAgreementReport();

public CompanyReportMgmt getCompanyReport();

public BillingReportMgmt getBillingReportMgmt();

public CashPostingReportMgmt getCashPostingReportMgmt();

public SysAdminReportMgmt getSysAdminReportMgmt();

public ReportMgmt getReportMgmt();

public void addReportRequestId(String reportRequestId);

public boolean lookupReportRequestId(String reportRequestId);

public boolean removeReportRequestIdFromCache(String reportRequestId);

public SpaceReportMgmt getSpaceReportMgmt();

public ViewerMgmt getViewerMgmt();

public RiskMgmtReportMgmt getRiskMgmtReportMgmt();

public UtilitiesReportMgmt getUtilitiesReportMgmt();

public CaActTrackingReportMgmt getCaActTrackingReportMgmt();

public AvStatsReportMgmt getAvStatsReportMgmt();

        public OraFinIfMgmt getOraFinIfMgmt();

        public PsFinIfMgmt getPsFinIfMgmt();

        public PaymentsIfMgmt getPaymentsIfMgmt();

        public SapFinIfMgmt getSapFinIfMgmt();

public RossFinIfMgmt getRossFinIfMgmt();

        public CatFimIfMgmt getCatFimIfMgmt();

        public CatExternalIfMgmt getCatExternalIfMgmt();

}
Actions
10. Re: Re: Wildfly : Poor Performance JNDI lookup

smarlow Sep 12, 2013 12:00 PM (in response to ismsteve)
You can proceed however you like but you could try commenting out all of the referenced beans and the code that references them. If that improves performance on the first invocation, you can divide and conquer from there.

For example:
/* @EJB private AgreementMgmt agreementMgmt; */ public AgreementMgmt getAgreementMgmt() { // return agreementMgmt; return null; }
Actions
11. Re: Wildfly : Poor Performance JNDI lookup

ismsteve Sep 12, 2013 4:16 PM (in response to ismsteve)

Update
I played around with this all day today and these are my findings.
I switched the server to use regular remoting over 4447 but got an error on the server when tried to connect:
==============================================================================
Error
==============================================================================
16:05:32,111 ERROR [org.jboss.remoting.remote.connection] (Remoting "pwtest" I/O-1) JBREM000200: Remote connection failed: java.io.IOException: Received an invalid message length of 1195725856

So I switched to use the jboss-client.jar file that ships with EAP 6.1. This worked great!!

Now my look ups are taking 144ms. So my conclusion is the performance has something to do with http-remoting.
Actions
12. Re: Wildfly : Poor Performance JNDI lookup

jaikiran Sep 13, 2013 12:25 AM (in response to ismsteve)

Some of that code in the client application isn't necessary. Without looking at the actual application which can reproduce this, it's hard to say if that's contributing to this problem. I haven't yet seen this issue in our testsuite, so I still believe this is something to do with the configuration. Do you have an application which reproduces this against a clean installation of WildFly? If yes, can you please attach it?
Actions
13. Re: Wildfly : Poor Performance JNDI lookup

jaikiran Sep 13, 2013 2:50 AM (in response to ismsteve)

As for your "why does the forum hate me" question that you asked on IRC - it's the result of a very basic spam control technique that's implemented here due to surge in spam in the recent past. I won't go into the exact details here, but if you are curious just ping me on IRC.
Actions

Go to original post