D
dvoyat
Guest
Running OE11.5 StateLess appserver (using NameServer) (HPUx 11) Just recently spotted that our broker did fire 48 new agent in 3s. We've been running from 10 to 58 agent and almost all of the new agent get trimmed within an hour (rougly). Since the broker is running asbman is reporting a max Client queue depth of 22 which means that at worse we got 22 client request on the queue. The max agent is set to 75 which has not been reached. Server startup timeout as well request timeout (not applied as max agent not reached) are still the default ones 3s and 15s. This case happened some week ago and our appserver log setting makes the agent log no longer available but I can clearly see from broker log the 48 "started server" requests. I recently checked with some fresh agent start and I spotted a delay (6 mins) between broker log file requesting a new agent and agent log file mentionning the start of new agent. Bellow is an extract of broker log file reporting last new agent started today [16/11/03@10:23:08.789+0100] P-003568 T-S-0966 2 UB Basic Started server thread: S-0966. (8101) [16/11/03@10:23:08.856+0100] P-003568 T-S-0966 2 UB Basic Started server: /progress/dlc115/bin/_proapsv -logginglevel 3 -logfile /home/eucomm/EUrafgo/log/dbproc/EUrafgo.server.002994.log -ubpid 3568 -Ms 1 -logname EUrafgo -logentrytypes ASPlumbing,DB.Connects -logthreshold 500000000 -numlogfiles 3 -ASID 966 -ubpropfile /home/eucomm/properties/ubroker.properties -ipver IPv4 -pf /home/eucomm/EUrafgo/db/params/eugoAS_utf.pf (8108) [16/11/03@10:23:09.558+0100] P-003568 T-S-0967 2 UB Basic Started server thread: S-0967. (8101) [16/11/03@10:23:09.574+0100] P-003568 T-S-0967 2 UB Basic Started server: /progress/dlc115/bin/_proapsv -logginglevel 3 -logfile /home/eucomm/EUrafgo/log/dbproc/EUrafgo.server.002994.log -ubpid 3568 -Ms 1 -logname EUrafgo -logentrytypes ASPlumbing,DB.Connects -logthreshold 500000000 -numlogfiles 3 -ASID 967 -ubpropfile /home/eucomm/properties/ubroker.properties -ipver IPv4 -pf /home/eucomm/EUrafgo/db/params/eugoAS_utf.pf (8108) [16/11/03@10:23:09.575+0100] P-003568 T-S-0968 2 UB Basic Started server thread: S-0968. (8101) [16/11/03@10:23:09.587+0100] P-003568 T-S-0968 2 UB Basic Started server: /progress/dlc115/bin/_proapsv -logginglevel 3 -logfile /home/eucomm/EUrafgo/log/dbproc/EUrafgo.server.002994.log -ubpid 3568 -Ms 1 -logname EUrafgo -logentrytypes ASPlumbing,DB.Connects -logthreshold 500000000 -numlogfiles 3 -ASID 968 -ubpropfile /home/eucomm/properties/ubroker.properties -ipver IPv4 -pf /home/eucomm/EUrafgo/db/params/eugoAS_utf.pf (8108) [16/11/03@10:23:09.589+0100] P-003568 T-S-0969 2 UB Basic Started server thread: S-0969. (8101) [16/11/03@10:23:09.616+0100] P-003568 T-S-0969 2 UB Basic Started server: /progress/dlc115/bin/_proapsv -logginglevel 3 -logfile /home/eucomm/EUrafgo/log/dbproc/EUrafgo.server.002994.log -ubpid 3568 -Ms 1 -logname EUrafgo -logentrytypes ASPlumbing,DB.Connects -logthreshold 500000000 -numlogfiles 3 -ASID 969 -ubpropfile /home/eucomm/properties/ubroker.properties -ipver IPv4 -pf /home/eucomm/EUrafgo/db/params/eugoAS_utf.pf (8108) [16/11/03@10:23:09.888+0100] P-003568 T-S-0970 2 UB Basic Started server thread: S-0970. (8101) [16/11/03@10:23:09.896+0100] P-003568 T-S-0970 2 UB Basic Started server: /progress/dlc115/bin/_proapsv -logginglevel 3 -logfile /home/eucomm/EUrafgo/log/dbproc/EUrafgo.server.002994.log -ubpid 3568 -Ms 1 -logname EUrafgo -logentrytypes ASPlumbing,DB.Connects -logthreshold 500000000 -numlogfiles 3 -ASID 970 -ubpropfile /home/eucomm/properties/ubroker.properties -ipver IPv4 -pf /home/eucomm/EUrafgo/db/params/eugoAS_utf.pf (8108) [16/11/03@10:23:10.009+0100] P-003568 T-S-0971 2 UB Basic Started server thread: S-0971. (8101) [16/11/03@10:23:10.025+0100] P-003568 T-S-0971 2 UB Basic Started server: /progress/dlc115/bin/_proapsv -logginglevel 3 -logfile /home/eucomm/EUrafgo/log/dbproc/EUrafgo.server.002994.log -ubpid 3568 -Ms 1 -logname EUrafgo -logentrytypes ASPlumbing,DB.Connects -logthreshold 500000000 -numlogfiles 3 -ASID 971 -ubpropfile /home/eucomm/properties/ubroker.properties -ipver IPv4 -pf /home/eucomm/EUrafgo/db/params/eugoAS_utf.pf (8108) and bellow agent log file reporting these start [16/11/03@10:29:05.843+0000] P-016897 T-000001 2 AS AS Application Server Startup. (5473) [16/11/03@10:29:06.527+0000] P-016898 T-000001 2 AS AS Application Server Startup. (5473) [16/11/03@10:29:06.647+0000] P-016899 T-000001 2 AS AS Application Server Startup. (5473) [16/11/03@10:29:06.810+0000] P-016900 T-000001 2 AS AS Application Server Startup. (5473) [16/11/03@10:29:06.910+0000] P-016907 T-000001 2 AS AS Application Server Startup. (5473) [16/11/03@10:29:06.981+0000] P-016906 T-000001 2 AS AS Application Server Startup. (5473) With my current understanding when all our agent are active the broker should wait 3s (server startup timeout) before started a new agent. There's nothing clear in the doc saying how many new agent started but as a quick guess it shouldn't be more than the current client queue at the time it happens. Also how to interpret the 6mins delay between broker log showing a new agent request and agent log showing the new agent started. We don't have any startup, activate, connect,..... procedure defined and the appserver and connected database are on same server. Database log file is not showing anything and we haven't been facing anything critical with the application on the day the appserver peak occured. There's something weird at some point so if anyone has clue or experience this is more than welcome ;-) Rgds Denis
Continue reading...
Continue reading...
