Hi,

This weird problem occurs in the following environment:
AEP 7.0.2.0303
AAOD 7.0.1.0804

There are many local type module calls in the application. Sometimes when a local module is started, instead of its first node, the OD starts a previous node (servlet).
Example trace log:

20/01/2016 14:06:38:085 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : SetLog_SERV_FRAUD
20/01/2016 14:06:38:085 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Popped Stack Frame [/Topnet_Greeting]
20/01/2016 14:06:38:085 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Module Local Call to : [WriteLog/Start]
20/01/2016 14:06:38:085 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Pushed Stack Frame [/WriteLog]
20/01/2016 14:06:38:085 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : request url copy is [http://lvphavyas2:8080/Topnet_Postpaid/SetLog_SERV_FRAUD]
20/01/2016 14:06:38:085 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : location is [/WriteLog/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:085 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : redirecting to [http://lvphavyas2:8080/WriteLog/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:088 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : Start
20/01/2016 14:06:38:088 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Creating variable [vdu] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUVariableFactory]
20/01/2016 14:06:38:088 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Creating variable [vdu_cache] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUCacheVariableFactory]
20/01/2016 14:06:38:089 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : prepareLog
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | WriteLog:prepareLog | _____Input params: Service=SERV_FRAUD | Event=-
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | WriteLog:prepareLog | _____Input param Event is not set, skip logging
20/01/2016 14:06:38:089 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : writeLog
20/01/2016 14:06:38:089 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : DummyNode
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | WriteLog:DummyNode | _____
20/01/2016 14:06:38:089 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : End
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : request url copy is [http://lvphavyas2:8080/WriteLog/End]
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : location is [/Topnet_Postpaid/DB_Call_TOP_CHECK_FRAUD?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:089 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : redirecting to [http://lvphavyas2:8080/Topnet_Postpaid/DB_Call_TOP_CHECK_FRAUD?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:091 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : DB_Call_TOP_CHECK_FRAUD
20/01/2016 14:06:38:091 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Popped Stack Frame [/WriteLog]
20/01/2016 14:06:38:091 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Assigning [vdu_cache:primary_ani] to [Call_TOP_CHECK_FRAUD:P_MSISDN]
20/01/2016 14:06:38:091 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | Topnet_Postpaid:DB_Call_TOP_CHECK_FRAUD | _____ | Call_TOP_CHECK_FRAUD:P_MSISDN : 381xxxxxxxxx
20/01/2016 14:06:38:091 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Executing DB statement : [{ call VIP_IVR.TOP_CHECK_FRAUD ( ?, ?) }]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | Topnet_Postpaid:DB_Call_TOP_CHECK_FRAUD | _____ | Call_TOP_CHECK_FRAUD:STATUS : 0
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression1] Expression [Call_TOP_CHECK_FRAUD:STATUS] String Equal [0]
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression2] Expression [vdu_cache:vip__DOT__suspended] String Equal [CA]
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression3] Expression [vdu_cache:vip__DOT__suspended] String Equal [CS]
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : Mod_Collection
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Overriding [VIP_Service/Start] with [Topnet_Collection/Start]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Module Local Call to : [Topnet_Collection/Start]
20/01/2016 14:06:38:134 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Pushed Stack Frame [/Topnet_Collection]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : request url copy is [http://lvphavyas2:8080/Topnet_Postpaid/Mod_Collection]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : location is [/Topnet_Collection/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:134 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : redirecting to [http://lvphavyas2:8080/Topnet_Collection/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:136 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : DB_Call_TOP_CHECK_FRAUD
20/01/2016 14:06:38:137 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Popped Stack Frame [/Topnet_Collection]
20/01/2016 14:06:38:137 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Not able to save posted variable information [AnyKey1___noinputcount]
20/01/2016 14:06:38:137 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Not able to save posted variable information [AnyKey1___nomatchcount]
20/01/2016 14:06:38:137 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Assigning [vdu_cache:primary_ani] to [Call_TOP_CHECK_FRAUD:P_MSISDN]
20/01/2016 14:06:38:137 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | Topnet_Postpaid:DB_Call_TOP_CHECK_FRAUD | _____ | Call_TOP_CHECK_FRAUD:P_MSISDN : 381xxxxxxxxx
20/01/2016 14:06:38:137 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Executing DB statement : [{ call VIP_IVR.TOP_CHECK_FRAUD ( ?, ?) }]
20/01/2016 14:06:38:179 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : session id:xlvphavympp1-2016020130633-7 | Topnet_Postpaid:DB_Call_TOP_CHECK_FRAUD | _____ | Call_TOP_CHECK_FRAUD:STATUS : 0
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression1] Expression [Call_TOP_CHECK_FRAUD:STATUS] String Equal [0]
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression2] Expression [vdu_cache:vip__DOT__suspended] String Equal [CA]
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : [expression3] Expression [vdu_cache:vip__DOT__suspended] String Equal [CS]
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : Mod_Collection
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Overriding [VIP_Service/Start] with [Topnet_Collection/Start]
20/01/2016 14:06:38:179 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Module Local Call to : [Topnet_Collection/Start]
20/01/2016 14:06:38:179 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : ** Pushed Stack Frame [/Topnet_Collection]
20/01/2016 14:06:38:180 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : request url copy is [http://lvphavyas2:8080/Topnet_Postpaid/Mod_Collection]
20/01/2016 14:06:38:180 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : location is [/Topnet_Collection/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:180 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : redirecting to [http://lvphavyas2:8080/Topnet_Collection/Start?___DDSESSIONID=9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main]
20/01/2016 14:06:38:182 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : Start
20/01/2016 14:06:38:182 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Creating variable [vdu] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUVariableFactory]
20/01/2016 14:06:38:182 DEBUG - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Creating variable [vdu_cache] from factory [com.avaya.sce.runtime.connectivity.ic.pdc.VDUCacheVariableFactory]
20/01/2016 14:06:38:182 INFO - 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main : Using SCESession 9836ECDFCC940D65215B7624AE7D5339:/Topnet_Main servlet : SetLog_SERV_COLL

There is another system with AEP 6 and OD 6, very same application structure, and it works fine long ago.
Is it a known issue maybe? Please advise.

• Tomcat - On some versions of Tomcat you may encounter problems with Tomcat closing a socket too soon when it sends a redirect; specifically, if there are 2 redirects back to back without a VXML page being returned. To alleviate this, use the connectionLinger property in the connector configuration with a minimum value of 1. It is not known if this behavior is exhibited on other application servers.

It seems this Tomcat setting didn't help. I tried the setting in the server.xml of Tomcat this way:

<Connector port="8080" protocol="HTTP/1.1"
connectionTimeout="20000" connectionLinger="10000"
redirectPort="8443" />

I tried first with value 1, then 10, then i found that it is milliseconds. i tried 1000, then 10000, but it didn't help. Of course, each time i restarted Tomcat.

Did i do it right?

What version of tomcat are you using now and what version were you using in OD 6?

Also, can you get a trace.log from or and a matching sessionslot from the voice browser so we can see what happened in the voice browser on the redirect request.

In the meantime i found a workaround: i added an empty VXML form to that module which previously had no any.
This solved the issue.