In the world of software development, it becomes so difficult many a times to analyze and detect the cause of unintended /exceptional behaviour of software Applications due to lengthy, cryptic and sphagetti codes that can be understood only by the intelligentia who has written the code. I was presented with such a situation of analyzing the problem recently and I treaded with fear. But once having done the analysis I am compelled to share my experience and just for a moment it flashed to me what would be the conversation between Dr. Watson and Sherlock Holmes if they were confronted with a scenario of investigating an exception in a software Application. I have attempted herein to narrate an imaginary script of such an investigation, with due apologies to our beloved author Sir Arthur Conon Doyle obviously expecting some gap between my narration and the great author’s narration. Quote Dr.Watson: Holmes, I have collected all the transaction log files and the snapshot of the code that is relevant for this Application. Holmes: Great! Were you able to analyze them? Dr. Watson: With all these artefacts, it is difficult for me to understand where to begin. Holmes: C'mon doctor! You are such an experienced medical practitioner; you know where to start. You always start with the symptom and try to ascertain the cause. Apply the same analogy here. Dr. Watson: I wonder if it were to be so easy. In treating patients, there is a person to express the symptom, whom you can interrogate and ascertain the cause of the symptom. But here we have only papers. Holmes: That is the difference between you and me. While you try to see each as a specialized area, I first try to generalize and then branch into specialized areas where required. Let me try to analyze it. Dr. Watson: Good luck Holmes! Ask me the artefacts that you require and I will provide it to you one by one. Holmes: First give me the transaction log file of the Application. Dr.Watson: Here you go.< table border="1"cellspacing="0" cellpadding="0">< tbody><tr>< td valign="top" width="47">1</td><td valign="top" width="559">14:31:00.731:Stored21001-MotoMMI-803888858 in $mondReceiverCompanyName</td>< /tr><tr>< td valign="top" width="47">2</td><td valign="top" width="559">14:31:00.731:Stored21001-MotoMMI-803888858 in $mondSenderCompanyName</td>< /tr><tr>< td valign="top" width="47">3</td><td valign="top" width="559">14:31:00.731:StoredCHOICE0319_50753567B in $inputParam1</td>< /tr>< tr>< tdvalign="top" width="47">4</td>< td valign="top"width="559">14:31:00.732:Stored 21001-MotoMMI in$currentPartnerIdentifier</td>< /tr>< tr>< tdvalign="top" width="47">5</td>< tdvalign="top" width="559">14:31:00.732:ExecutingMap:ShipConfirmReceivedAtR12-PF - 1.00</td>< /tr>< tr>< tdvalign="top" width="47">6</td>< tdvalign="top" width="559">14:31:00.732:StoredCHOICE0319_50753567B in $mondProcessInstanceId</td>< /tr><tr>< td valign="top" width="47">7</td><td valign="top" width="559">14:31:00.732:**callingmapping ShipConfirmReceivedAtR12 - 1.00</td>< /tr>< tr><td valign="top" width="47">8</td>< tdvalign="top" width="559">14:31:00.732:ExecutingMap:ShipConfirmReceivedAtR12 - 1.00</td>< /tr>< tr>< tdvalign="top" width="47">9</td>< tdvalign="top" width="559">14:31:00.732:Stored  in $billOfLaddingNumber</td>< /tr>< tr>< tdvalign="top" width="47">10</td>< tdvalign="top" width="559">14:31:00.732:Extracted BOLNO :" " ,   PID : "CHOICE0319_50753567B"  ,DocNo : "null"</td>< /tr>< tr>< tdvalign="top" width="47">11</td>< tdvalign="top" width="559">14:31:00.732:Stored  in $truckID</td>< /tr>< tr>< td valign="top"width="47">12</td>< td valign="top"width="559">14:31:00.732:Stored CHOICE0319 in$inputParam1</td>< /tr>< tr>< td valign="top"width="47">13</td>< td valign="top"width="559">14:31:00.732:Stored 50753567B in$billOfLaddingNumber</td>< /tr>< tr>< tdvalign="top" width="47">14</td>< td valign="top"width="559">14:31:00.732:In add event, getting existing txnprocessmodel for:CHOICE0319_50753567B</td>< /tr>< tr>< tdvalign="top" width="47">15</td>< td valign="top"width="559">14:31:00.736:Existing ProcessModel not foundfor:CHOICE0319_50753567B</td>< /tr>< tr>< tdvalign="top" width="47">16</td>< tdvalign="top" width="559">14:31:00.736:Creating a newProcessInstance Model</td>< /tr>< tr>< td valign="top"width="47">17</td>< td valign="top"width="559">14:31:00.739:Created a new ProcessInstance model withId:-1</td>< /tr>< tr>< td valign="top"width="47">18</td>< td valign="top"width="559">14:31:00.742:Stored 0 in $retryAttempt</td></tr>< tr>< td valign="top"width="47">19</td>< td valign="top"width="559">14:31:00.742:Stored 50753567B in $billOfLaddingNumberR</td></tr>< tr>< td valign="top"width="47">20</td>< td valign="top"width="559">14:31:00.742:Stored 0 in $</td>< /tr><tr>< td valign="top" width="47">21</td><td valign="top" width="559">14:31:00.742:CallingFunction:createTaskToCheckReceivedBOL</td>< /tr>< tr>< tdvalign="top" width="47">22</td>< tdvalign="top" width="559">14:31:00.742:Stored  in $SQL</td>< /tr>< tr>< td valign="top"width="47">23</td>< td valign="top"width="559">14:31:00.745:Executing Method fetchSQL() in Shell Script</td></tr>< tr>< td valign="top"width="47">24</td>< td valign="top"width="559">14:31:00.745:FetchingDocumentType:Moto-ThinClient-Queries IntVersion:1.00</td>< /tr><tr>< td valign="top" width="47">25</td><td valign="top" width="559">14:31:00.750:FetchingQuery:SelectReceivedBOLFromR12</td>< /tr>< tr>< tdvalign="top" width="47">26</td>< tdvalign="top" width="559">14:31:00.754:FetchedQuery:SELECT data_field1 bol  FROM c_apps.c_ship_confirm_headerheader,       c_apps.c_ship_confirm_details detailsWHERE header.transaction_id = details.transaction_id   ANDrecord_sub_type = 'BOL'   AND data_field1 = ?   AND UPPER(status) = 'SUCCESS'  AND header.last_update_date >sysdate-2</td>< /tr>< tr>< td valign="top"width="47">27</td>< td valign="top" width="559">14:31:00.754:</td></tr>< tr>< td valign="top"width="47">28</td>< td valign="top"width="559">14:31:00.754:</td>< /tr>< tr>< tdvalign="top" width="47">29</td>< tdvalign="top" width="559">14:31:00.754:Executed ShellScript method:fetchSQL() successfully</td>< /tr>< tr>< tdvalign="top" width="47">30</td>< tdvalign="top" width="559">14:31:00.754:Operator if basedon $billOfLaddingNumberR, results in: true</td>< /tr><tr>< td valign="top" width="47">31</td><td valign="top" width="559">14:31:00.754:CompletedCallFunction:createTaskToCheckReceivedBOL</td>< /tr>< tr><td valign="top" width="47">32</td>< tdvalign="top" width="559">14:31:00.754:CompletedCallMapping</td>< /tr>< tr>< td valign="top"width="47">33</td>< td valign="top"width="559">14:31:00.754:Operator if based on $mondErrorLog,results in: true</td>< /tr>< tr>< tdvalign="top" width="47">34</td>< tdvalign="top" width="559">14:31:00.754:Exceptionencountered 20035:Document status can be set only after the document isfetched</td>< /tr>< tr>< td valign="top"width="47">35</td>< td valign="top"width="559">14:31:00.754:Line Number 5</td>< /tr></tbody>< /table>< strong>Holmes</strong>:You will noticein line 34 that an exception is raised. <strong>“Exception encountered20035:Document status can be set only after the document isfetched”</strong>.< strong>Dr. Watson</strong>: 20035exceptions encountered! That is a large volume.<strong>Holmes</strong>: That is not the number of exceptionsencountered. It must be the identification number given to this type of anexception.< strong>Dr. Watson</strong>: Oh, now I understand. Butit is hard for me to believe that an Application can raise 20035 types ofexceptions; God save the end users!< strong>Holmes</strong>: Youwill also notice in line 33 <strong>“Operator if based on $mondErrorLog,results in: true”</strong>.  The fact that there is a<strong>mondErrorLog</strong> indicates that there was an errorprior to this step in the map.< strong>Dr. Watson</strong>: But Ido not see any other line indicating exception in the earlier steps.<strong>Holmes</strong>: That is why we have been asked to investigatethis error. Else, the Application support team themselves would have known thecause of the problem. Now give me the snapshot of the base map in which thisexception is raised.< strong>Dr. Watson</strong>: How do I knowthat? I guess it is a wrong question directed to me.<strong>Holmes</strong>: If you traverse backwards in the log file, youcan find the map name in Line no. 5 - <strong>ShipConfirmReceivedAtR12-PF</strong>.<strong>Dr. Watson</strong>: OK, Here it is.

You notice this is where the exception is trapped.Dr. Watson: I thought you would trap onlyculprits.Holmes: You are humorous Watson.Trapping the exception is a mechanism to trap the culprits in the software code.Dr. Watson: The other log lines appear toindicate normal behaviour.Holmes: You are right.Now, let us move on to the Function.Dr.Watson:Give me 30 minutes to get ready. By the way, whichfunction are you referring to?Holmes: Don’t besilly Watson. When I said Function, I meant the software code that is createdas a re-usable piece of logic. Can you give me the snapshot of the Function please? From Line 21 to 31 of the log, it is clear that the map is executingthefunction ‘createTaskToCheckReceivedBOL’.Dr. Watson: Sorry, here it is.

Line 30 of the log shows“Operator if based on $billOfLaddingNumberR, results in:true”. It is clear that the map is evaluating the condition‘if $billOfLadingNumberp.Dr.Watson: Why do you traverse back and forth reading the logfiles? You started with line 34, then went back to line 30, then further backto line 21 and now again to line 30.Holmes: Ifyou read the entire log file at a time, you will get lost amidst lot of information that are not relevant at a particular point in time. Read only the relevantlines and you will find it easier to digest.Dr.Watson: Advise taken.Holmes: Ah!We have come to a logical stage of conclusion. As expected earlier, the map issetting an error here. It is time for a glass of whisky Watson.Dr. Watson: How do you say so? I thought we have justfound the first place where it has caused the problem.Holmes: Here is my intermediary conclusion Watson -a)    The Function‘createTaskToCheckReceivedBOL’ is returning anexception (i.e, it is creating mondErrorLog). This fact is clear from line 30 of the log – “Operator if based on $billOfLaddingNumberR, resultsin: true” b)    The parent map‘ShipConfirmReceivedAtR12-PF’ is trapping thisexception as seen in line 33 of the log - “Operator if based on$mondErrorLog, results in: true” c)     The map is trying to update the status of the document to an error status.d)    It is clear from the log line 34 which reads as‘…….Document status can be set only after the document isfetched’, that a document has to be fetched before its status can be updated. But there is no place in the mapping where any document isfetched. Hence the exception, which our client asked us to investigate.Dr. Watson: Agreed Holmes. But why is the Function‘createTaskToCheckReceivedBOL’ raising an error first of all?Holmes: By looking at the snapshot of the Function, we note that variable‘billOfLadingNumberP’ is not set anywhere in the mapping. The only other alternative is that this variable should be an input parameter. Give me the snapshot of the Function parameters definition screen.Dr. Watson: Here it is.

Look at this. It is clear that<strong>‘billOfLaddingNumberP’</strong> is an input parameter andhas to be passed by the calling map. I hope you have the snapshot of the placewhere the Function is invoked in the calling map.< strong>Dr.Watson</strong>: (<i>After searching for 5 minutes…</i>) Ah!I found it< a href="http://mondcloud.com/wp/wp-content/uploads/2013/05/Blog-Picture-4.png">

By looking at the above snapshot, it is clear that ‘billOfLadingNumber’is passed by the calling map.Dr. Watson: But the Keyword is shown as ‘$billOfLaddingNumber’ (GOD! whoever taught spellings to the author of this map), while the input parameter to the function is ‘billOfLaddingNumberP’!Holmes: I have to appreciate the designers of this software. They had foresight to expect such human mistakes during the development and hence they seem to have handled it by using the Parameter index numbers instead of the Parameter names.Dr.Watson: How do you say that?Holmes: Because you see from Line no. 19 in the log that ‘billOfLaddingNumberP’ is passed -‘Stored 50753567B in $billOfLaddingNumberR’. If the designers had used parameter names, then the variable value should not have been there.Dr. Watson: GOD bless the designers for their foresight! Holmes: And finally, the cause is detected. Now it is time to have a large Whisky. You made me miss it by your continuous questions all this while.Dr.Watson: Definitely I do not hold you back now, if only you can clarify a small doubt. How do you say that the cause is detected? If the valueof ‘billOfLaddingNumberP’ is present, why has the condition tested true? Holmes: Elementary my dear Watson! The value of the variable‘billOfLaddingNumberP’ is alpha numeric‘50753567B’ and the code is testing for the condition ‘billOfLaddingNumberP’  as thoughit is a numeric variable.Unquote Friends, thoughI did the analysis of the problem and found it to be reasonably simple, simply because the logs were structured well and provided reasonably good reference points to the Application code, I used the much loved characters of Sherlock Holmes and Dr. Watson to narrate the analysis because it is a matter to be accepted albeit with great concern that generally Application Software code truly require the skills of nothing less than Sherlock Holmes to analyse. Dr.Watson would not be wrong too when he says ‘GOD save the end users’ who are continuously encountered with such mysteries.

‍