Dr. Debug's Advice

Dear friends of the debugging fun,

Today I thought I would share a fairly common issue that I have come across quite frequently in the past weeks.

When creating a new managed asset in the BPM Process Designer, you may receive an error like the following:

Now, what can we do to debug this? We'll use fiddler!

For those of you who do not yet know fiddler, below a short explanation.

Fiddler will act as an HTTP proxy and will need to be installed on the client.                                                                  
If all goes well it should capture ALL HTTP traffic on the client, which should include the HTTP communication between ProcessDesigner and ProcessCenter.                                                           
                                                                         
I will try my best in ASCII-Art:                                         
This is how the communication usually works                              
| Process Center Repository | <----------http(s)----------> | Process Designer |                                                               
                                                                         
When you run fiddler, it will looks like this:                           
                                                                         
| Process Center Repository | <----------http(s)----------> | Fiddler | <----------http(s)----------> | Process Designer |                       
                                                                         
This will allow us to look into all the details of the communication between ProcessCenter and Process Designer. Header Information, Cookies, response codes etc.                                                      
                                                                         
There are actually 2 versions of fiddler that you could use. A very light weight version named "fiddlercap" (www.fiddlercap.com), which basically only provides a small UI with a few buttons and options. This should be sufficient for just capturing data.                       
Please find below an IBM Support TV video with instructions on how  to use fiddlercap (starting at 2:40):                                                 
                                 

                                                                         
However, instead of recreating the problem in your browser you would simply recreate it in PD. Please remember to select the option "decrypt HTTPs traffic".                                                          
                                                                         
The second version is the full version of fiddler, with which you can (http://www.telerik.com/download/fiddler). This provides a lot of more options, but for recording we would also just need the "Decrypt HTTPs traffic" option to be enabled. For fiddler, we have another IBM Support TV video with instructions on how to record traffic:                                                   

Once you recorded the error, open fiddler and review the frames. You may see an HTTP call to  the /assetServlet URI. This is the one to look at!

What you may see is something like this:

http://myhost.com:9080/ProcessCenter/repository/assetServlet to    
https://myhost.com:9443/ProcessCenter/repository/assetServlet - so basically a redirect to the https port.                                                     
                                                                         

Now this indicates that you may not have set the "useHTTPSURLPrefixes" parameter to 'true' in your cluster-bpm.xml file.

The entry would usually look like this:                                  
                                                                         
<bpdServer xmi:type="BPMConfiguration:BPMProcessCenter" xmi:id="BPMProcessCenter_1404198504697" useHTTPSURLPrefixes="true" httpProtocolOnly="true">                                                 
                                                                         
The following link to our Knowledge Center provides you with the steps to take to update your settings:                                         
                                                                         
http://www-01.ibm.com/support/knowledgecenter/SSFTN5_8.5.5/com.ibm.wbpm.imuc.doc/topics/tconnect_to_pctr.html?cp=SSFTN5_8.5.5&lang=en

Once you have set the useHTTPSURLPrefixes to true, try again.

What this will do is it will prevent the redirect to the SSL port as the HTTPS URL will be used from the beginning. This will avoid the 302 redirect and the error.

And if this does not help, take two of these  and call me in the morning.

Your Dr. Debug

My dear Readers,

Today I wanted to share with you a recent performance issue that I came accross.

Symptoms

My patient reported that the deployment of a specific process application took hours to complete. The application had advanced content and the environment was Intranet only without any access to the Internet.

Diagnosis

In the logs I discovered several timeout exceptions, and digging deeper into the FFDCs I found this:

[...]

Caused by: org.eclipse.emf.ecore.xmi.PackageNotFoundException: Package with uri 'http://www.ibm.com/xmlns/prod/websphere/scdl/wsdl/6.0.0' not found.

[...]

Checking the affected Process Application showed that these URI-References were included in AIS. 

The exception stated that BPM was trying to find a so called SCDL-file (Service Component Definition Language) from an internet resource ('http://www.ibm.com/xmlns/prod/websphere/scdl/wsdl/6.0.0').  Since this environment had no internet access, it's pretty clear this request would fail as the file was unreachable. This caused delays and thereby causing the reported performance impact. 
A first thought is that all requests to this file would time out and the timeout period multiplied with the components pointing to the respective internet resource would add up to the total delay my patient complained about. But could we tackle this now?

Potential treatments

I could think of 2 possible options:

Option 1) Modify all Internet-References in the components of the Process Application

Option 2) Configure the environment in such a way that Internet-Requests get redirected to the localhost or an Intranet-Resource

As my patient's application contained a huge load of components that were referencing Internet-Resources, option 1 would have meant huge efforts. But option 2 needs to be handled with care. Redirecting requests to resources where the file is not present may cause side-effects in case the file requested is needed for important actions. Hence, the files should bemade available in the local/intranet environment to ensure they can be accessed by BPM. Or at least you should verify if the missing files are impacting your applications.

In this case, we determined that an EAR file was validated against the mentioned SCDL-file before the deployment. Since the file was just needed for validation and as it had no impact on the application itself, we went with option 2, which solved the problem.

I hope that some day this will also help you. 
And if it does not, take two of these  and call me in the morning.

Your Dr. Debug

Dear Readers,

Since I saw this issue a couple of times before, and as everybody will deploy something someday, I thought it would be worth a posting. 

Symptoms

• It appears our patient has a very bad flu and cannot deploy snapshots to his Process Server (PS) anymore
• He is using a golden topology and the issue is impacting several process applications
• The following exceptions occur in SystemOut.log of PS-AppTarget:

[10/27/14 23:36:39:757 EDT] 0000007d wle I Exception in EJB call [10/27/14 23:36:39:757 EDT] 0000007d wle E CWLLG2164E: Install did not complete successfully because of an unexpected exception. Error: C:**** com.lombardisoftware.client.delegate.BusinessDelegateException: CWLLG0433E: Tracking definitions were not sent successfully. Details: UOWManager transaction processing failed; nested exception is com.ibm.wsspi.uow.UOWException: javax.transaction.RollbackException ... Caused by: com.ibm.wsspi.uow.UOWException: javax.transaction.RollbackException ... 

Diagnosis

• Let's take a look at that exception. The „install did not complete successfully“ (CWLLG2164E) because „Tracking definitions were not sent successfully“ (CWLLG0433E). I see.
• So that makes me think... Hmm, tracking definitions... Isn't that stuff related to Performance Data Warehouse (PDW) and data defined in the process app/toolkit? And those are tracked there if I am not mistaken.
• Oh well, PDW-related data might be logged in the Support-Cluster. Worth a shot.
• The analysis in the SystemOut.log of the PS-Support-Cluster reveals the following:

[10/27/14 23:36:39:133 EDT] 00000035 XATransaction E J2CA0027E: An exception occurred while invoking prepare on an XA Resource Adapter from DataSource jms/DataDefLoaderConnectionFactory, within transaction ID {XidImpl: formatId(), gtrid_length(), bqual_length(), data()} : javax.transaction.xa.XAException: CWSIC8007E: An exception was caught from the remote server with Probe Id 3-013-0010. Exception: CWSIC2029E: This transaction cannot commit as an operation that was performed within the transaction boundary failed. The first operation that failed generated the following exception: com.ibm.ws.sib.processor.exceptions.SIMPLimitExceededException: CWSIK0025E: The destination DataDefLoaderQueueDestination.PSMECluster on messaging engine PSME.PERFDW.BPMCell.Bus is not available because the high limit for the number of messages for this destination has already been reached... ... Caused by: com.ibm.wsspi.sib.core.exception.SILimitExceededException: CWSIK0025E: The destination DataDefLoaderQueueDestination.PSMECluster on messaging engine PSME.PERFDW.BPMCell.Bus is not available because the high limit for the number of messages for this destination has already been reached.

• To sum it up the exception says that the destination DataDefLoaderQueueDestination.PSMECluster on messaging engine PSME.PERFDW.BPMCell.Bus is not available because the high limit for the number of messages for this destination has already been reached. Aha!
• Now THAT is the information I looked for. It seems that the limit of the DataDefLoaderQueue has been reached, hence tracking definitions could not be sent, and therefor the deployment failed.
• That does make sense, I guess.

Potential treatments

In order to heal the patient I'd recommend to clean up messages from the DataDefLoader-Queue. This should generate space for tracking definitions and deployments should not fail anymore with this exception.

To do so, browse your WAS Admin console, open the Runtime tab in Service Integration>Buses>bus_name>Bus members>Messaging engines for SingleCluster>cluster_name>Queue points>DataDefLoaderQueueDestination_Bus>messages (running messaging engine is required).

There are usually messages with content "Request PDW transfer" (approx. 20 Bytes large). These messages are just trigger messages for the PDW application to start tracking data transfers, and it is usually safe to delete them.

In additon we can go all the way with antibiotics which accelerates the treatment:

The patient might identify BPDs and toolkits where autotracking is enabled, see:

https://developer.ibm.com/answers/questions/163383/how-to-identify-processes-bpds-and-toolkits-where/

Furthermore, we might use a script to remove trigger messages, as desribed here:

https://developer.ibm.com/answers/questions/163750/how-to-resolve-a-comibmwsspisibcoreexceptionsilimi.html

And if that ain't helping, take two of these  and call me in the morning.

Your Doc D.

Dear Readers,

A while back we saw a case, where one of our customers wanted to expose a service as URL. As you know, the URL to access this service looks like this:

http://host_name:port/teamworks/executeServiceByName?processApp=acronym&serviceName=MyService

They now wanted to escape the '&' character with it's percent-encoded octet '%26', i.e. replacing '&' with '%26'. This however returned an error, stating "Project with name ... not found".

Now, why is this? The percent-encoded octet represents the '&' and they should be equivalent, shouldn't they?

Well, yes and no. The percent-encoded octet is equivalent to the '&' sign, correct.

However, as you will see in RFC3986 Section 2.2 the '&' is a reserved character in a URL. Escaping it will most likely change the way the application is interpreting the URL. And this is the case here. The '&' is a control character, a so-called sub-delimiter. And in our case here, it changes the way BPM interprets this URL.

So you should not escape the reserved characters in the above mentioned URL.

I hope this helps you overcoming problems in the future. And if it does not, take two of these and call me in the morning.
 

Yours

Dr. Debug

Dear Debuggers,

This week, I found something interesting. While the official fixlist for BPM 8.5.5 states that the iFix for JR50008 - MALFORMEDURLEXCEPTION OCCURS WHEN YOU ACCESS A MANAGED ASSET FILE - is included, the "versioninfo -long" command output run on any v8.5.5 system does not show it listed.

After some research I found, that JR50008 is not included in v855 and it is accidentally listed in the fixlist for this product version. We are working on getting this corrected.

If you need this fix on v855, you may simply install iFix JR50653 for v855. It does contain the code change for JR50008 and is available for v855.

And if JR50653 does not help you, take two of these  and call me in the morning.

Your Doc D

Dear Readers,

Today I would like to share with you an interesting case that I recently worked on.

Symptoms

Process Portal in BPM 7.5.1.1 showed several completed process instances, all with a certain task in state "new". Clicking the "Run" button for that task did not work. No Task was started, nothing happened. No new window opened, nothing changed.

Diagnosis

To further diagnose the problem, we looked at the Process Inspector in the Process Admin Console. Here we saw something pretty amazing:

The instance was marked as completed, and so was the task. At least in the left pane of the Process Inspector. The right frame showed the task as "new". Which is fairly interesting as they contradict each other.

As a next step we had a look at the LSW_TASK table in the BPM database. This showed a status of "11" - which is "new".

So the right hand side and the Process Portal were correct. This task still was in the status "new". So we were facing an inconsistency. As all these bogus instances were listed in Process Portal, our main goal was to get all those tasks completed and get rid of the instances.

Potential Treatment

Well, I could think of 2 possible options to mark those tasks as completed.

1. Manipulate the database - too risky! Never do that unless IBM Support advised you to and provided clear instructions.

2. Use the REST API - Bingo! As described in the IBM Knowledge Center we can use the REST API to finish tasks. We simply need to use this POST method:

POST /rest/bpm/wle/v1/task/{taskId}?action={complete} 

Guess what?! It worked! We simply performed this step for all the tasks that were still marked as "new" and were able to resolve the problem.

However, we were not able to find the cause, why these inconsistent data were present

I hope that one day this may help you solving a problem in your environment. And if it does not, take two of these  and call me in the morning.
 

Your Doctor Debug

Hi Fellows,

Thanks to our Community Member Bernd I now have a brand new profile picture and our community has a neat new Community Image. 

Thank you Bernd for the great drawings!
Your Doc D.

Dear Debuggers,

Today I am going to present you another interesting anamnesis. Enjoy!

Symptoms

• The patient has recently installed a fix pack (in this particular case it was on WLE 7.2.0. FP5)

• After installation, the patient discovered that changes to environment variables were not picked up by the process app

• For instance, our patient had an environment variable called „testVar“ which was set to 25 for DEVELOPMENT before the upgrade was performed. Now after changing it to another value (like 100, see screenshot), the value of 25 was picked up every time.
   

  

   

• At the patient the symptom can be confirmed by our excellent diagnosis tool - the Execution Evaluator:
   

  

   

• Even creating a new snapshot did not help the patient 

• The patient was quite suprised as there were no issues in that respect before WLE/BPM had been upgraded

Diagnosis

The reproduction attempt of the symptom at a test person (test environment – not upgraded) showed a working scenario. Here, the environment variables switched to the proper values.

A further test on the patient was to create and test another environment variable. At this test the patient showed no symptom.

Summarized, Dr. Debug faced the following situation:

•        The symptom is related to process applications which existed before the upgrade

•        After the upgrade the environment variables revealed an inconsistency

•        This inconsistency was not saved in the .twx-file as a further test person showed no symptoms

•        Hence, it seemed to belong to the database and a specific references there

Dr. Debug's assumption was that some references of the affected process app might have gotten corrupted by the upgrade. He further thought, an export of the process application before the upgrade and an import back after the upgrade might have prevented this issue.

Potential treatments

Now, what could Dr. Debug try to heal the patient?

Right, he can try to treat this disease by creating new database entries and references.

For instance, a potential treatment can be the cloning of the affected process application. By doing so, new references in the database are created and all environment variables should work as expected.

Another option would be to remove the affected artifacts and create new ones. However, this needs to comprimise all affected artifacts.

It seems that the better option is the cloning since an entirely new process application is created.

Hence the cloning approach was Dr. Debug's Advice in this case. The result was very positive. All environment variables took the proper values according to the environment type used. Hence, the patient no longer showed the symptoms and Dr. Debug's Advice helped another patient back on his feet.

And if this does not help in your case, take two of these  and call me in the morning.

Your Doc D.

Dear Friends of the Debugging-Fun,

A few days ago, I was presented an interesting issue. One of my customers experienced an unacceptable wait problem while starting their BPM AppCluster.
As always, the first step is to look at the SystemOut.log to see, if there is anything interesting in there.
In this case, there were a vast numer of DB queries, similar to this:

select data,version_id from lsw_bpd where version_id in (select distinct ver.po_version_id from lsw_po_versions ver inner join lsw_snapshot snap on (ver.branch_id=snap.branch_id and ver.start_seq_num<=snap.seq_num and ver.end_seq_num > snap.seq_num) where ver.po_type=25 and snap.name is not null)

Yep, yet again another Performance debugging.

As my customer mentioned the delay starts right then, when cache settings were loaded, I checked the SystemOut.log for anything Cache related during the start-up.

I found the following line:

000000ae wle I CWLLG2155I: Cache settings read have been from file file:

/opt/IBM/BPM/v85/BPM/Lombardi/process-server/lib/procsrv_resources.jar!/LombardiTeamWorksCache.xml.

As you can see, the threadID for that activity is 000000ae. So I grepped for 000000ae to see the whole thread.

And I was quite surprised to see a !9 MINUTE! delay in the start-up. You know, most of the performance cases we see are on a very high level, meaning we are talking of improvements of a few seconds. But this one, I have to tell you, had a good point. Now 9 minutes is an awefully long time to wait. 9 minutes - that is about 2 cups of coffee. Too long, as you will most likely agree.

From the information in the logs it seemed that the delay was related to the Cache, as it occured between the cache settings being loaded and the cache being initialized.

So, where could this be coming from? Maybe some slow DB causing this delay? Well, we do not yet have enough information to tell, hence we need some traces.

The following trace string is the one to start with for such issues:

*=info:WLE.*=all:WAS.clientinfopluslogging=all:com.ibm.ws.rsadapter.jdbc.WSJdbcPreparedStatement=all

The trace.log gives us more info.

We can see the known code from the screenshot above "CWLLG2155I" and some cache activities for e.g. LRU Cache, BDAC(BusinessDataAliasCache), etc.

[3/24/15 9:10:09:109 EET] 000000ae wle           I   CWLLG2155I:  Cache settings read have been from file file:/opt/IBM/BPM/v85/BPM/Lombardi/process-server/lib/procsrv_resources.jar!/LombardiTeamWorksCache.xml
[3/24/15 9:10:09:749 EET] 000000ae wle_versionin 3 com.lombardisoftware.utility.collections.LRUCache createCache maxSize :64
[3/24/15 9:10:09:749 EET] 000000ae wle_versionin 3 com.lombardisoftware.utility.collections.LRUCache <init> New LRUCache created :853f63c0
 

Here we can see the Cache size, which reminds me of a useful article on how to configure them for tuning purposes. Find the link here.

[3/24/15 9:10:17:496 EET] 000000ae wle           1 com.lombardisoftware.core.cache.LocalCache initCache BusinessDataAliasesCache initC()
[3/24/15 9:10:17:496 EET] 000000ae wle           1   BDAC - initialized
[3/24/15 9:10:17:496 EET] 000000ae wle           1   BDAC - loadCacheData(name=BusinessDataAliasesCache, key=*
[3/24/15 9:10:17:500 EET] 000000ae wle           > com.lombardisoftware.client.delegate.common.ServiceLocator lookup ENTRY jdbc/TeamWorksDB

I took a deeper look at the cache activities and stumbled across the following:

The BDAC cache load started at: 09:10:17

And it finished at: 09:16:26

So, what does this mean? These are 6 minutes only for the BDAC cache (which is 2/3 of 9 minutes load time). Aha!

So, now we need some further info on the BDAC. Upon further research, I found this:

http://www-01.ibm.com/support/docview.wss?uid=swg1JR47818

*  Searchable business data aliases are    *

*  the columns that you can use in saved   *

*  searches, the TWSearch API, and the     *

*  REST Search API. If you set the         *

*  <use-business-aliases-for-process-      *

*  instances> property value to "false",   *

*  the list of searchable business data    *

*  aliases are returned based on           *

*  snapshot definitions.                   *

This APAR was introduced for BPM 7.5.1.2 with a new property named <use-business-aliases-for-process-instances>.
The default value for that property is " T R U E ".

TRUE means that the list of searchable Business data aliases are returned only when they are used in actual process instances.

If FALSE is selected, the Business data aliases will be created at the server startup already BEFORE the first access by process instances. If there is  a large number of BPDs, searching all the BPDs can take a very long time.

The more process applications are deployed on server the more aliases will be created, the longer the cache load time takes.

So, if this was introduced in 7.5.1.2 why did I still see this in 8.5.5? APAR JR47818 is part of BPM v8.5.5.

Hm, what could have happened here?

As my grandmother would have said: Never trust a running config (if she had known what a running config was).  Hence lets have a look at the 99local.xml file on my BPM 8.5.5 setup to verify the default configuration for that attribute.

Indeed, the value is set to " F A L S E " !

Checking the customer's 99local.xml and 100Custom.xml showed the same.

Bingo!

Let's wrap up our findings:

1) APAR JR47818 (with BPM 7.5.1.2 ) introduced a new property <use-business-aliases-for-process-instances>. The default value for that property is " T R U E ".

2) BPM 8.5.5.0 includes APAR JR47818 but in that version the default value for the property <use-business-aliases-for-process-instances>  is " F A L S E ".

That is quite a surprise! But at least, we know what to do next. 
Exactly! We need to change that property to true.

So I advised my customer to change the setting for that property to " T R U E " and the problem was solved.

As you can see, sometimes all it takes is a bit of time and research to tackle these kind of issues. 
And if this article does not help, take two of these  and call me in the morning.

Yours,
Doc D.