KpyM Telnet/SSH Server - Forum

Why do disconnects take 4-5 seconds?
sr	Why do disconnects take 4-5 seconds?	Jun 11 2008 16:18

I'm scripting some work on the KTS telnet server with expect. It seems that every so often, my script will get confused. After peeking around a bit, here's my best estimate understanding of the problem - In kts.ini - allow_disconnected_sessions =0 My script does a login, runs some commands, and exits. Run individually, this seems fine. From log\kts-log.txt 4808 : 3780 2008- 6-11 9: 2:19 887 : 0: KTS connected to 127.0.0.1:50369 6132 : 1148 2008- 6-11 9: 2:20 500 : 0: term-ssh.exe started 6132 : 1148 2008- 6-11 9: 2:20 569 : 0: connected to 127.0.0.1:50369 6132 : 5244 2008- 6-11 9: 2:24 4 : 0: login accepted: [ qa ] 6132 : 1896 2008- 6-11 9: 2:37 76 : 0: disconnected 6132 : 1896 2008- 6-11 9: 2:41 119 : 0: shutdown 6132 : 1896 2008- 6-11 9: 2:41 124 : 0: session.exe end Notice that disconnect was done at 9:2:37, while the session ended at 9:2:41 - a 4 second delay. When I run the script in quick succession, notice how the previous session and new one overlap. 4808 : 3780 2008- 6-11 9: 4: 0 45 : 0: KTS connected to 127.0.0.1:50373 288 : 5468 2008- 6-11 9: 4: 0 280 : 0: term-ssh.exe started 288 : 5468 2008- 6-11 9: 4: 0 328 : 0: connected to 127.0.0.1:50373 288 : 3992 2008- 6-11 9: 4: 3 703 : 0: login accepted: [ qa ] 288 : 5512 2008- 6-11 9: 4:16 838 : 0: disconnected 4808 : 3780 2008- 6-11 9: 4:19 481 : 0: KTS connected to 127.0.0.1:50375 1212 : 4004 2008- 6-11 9: 4:19 668 : 0: term-ssh.exe started 1212 : 4004 2008- 6-11 9: 4:19 721 : 0: connected to 127.0.0.1:50375 288 : 5512 2008- 6-11 9: 4:20 865 : 0: shutdown 288 : 5512 2008- 6-11 9: 4:20 867 : 0: session.exe end 1212 : 5228 2008- 6-11 9: 4:23 94 : 0: login accepted: [ qa ] 1212 : 2064 2008- 6-11 9: 4:36 200 : 0: disconnected 4808 : 3780 2008- 6-11 9: 4:38 772 : 0: KTS connected to 127.0.0.1:50377 4916 : 4384 2008- 6-11 9: 4:39 59 : 0: term-ssh.exe started 4916 : 4384 2008- 6-11 9: 4:39 113 : 0: connected to 127.0.0.1:50377 1212 : 2064 2008- 6-11 9: 4:40 229 : 0: shutdown 1212 : 2064 2008- 6-11 9: 4:40 233 : 0: session.exe end 4916 : 4172 2008- 6-11 9: 4:42 467 : 0: login accepted: [ qa ] 4916 : 3736 2008- 6-11 9: 4:55 624 : 0: disconnected 4916 : 3736 2008- 6-11 9: 4:59 660 : 0: shutdown 4916 : 3736 2008- 6-11 9: 4:59 666 : 0: session.exe end Is there a way to prevent this? Every so often, the output gets served from the old session (or so it seems!) but it is garbled. This causes my scipt monitoring the output to fail. I as wondering is there is a better way to get this issue sorted out? I have a few thousand cases to run, so minimizing the wait time will be most appreciated. -shishir
sr		Jun 11 2008 16:55

A couple of follow ups: 1. I'm using telnet. Why does term-ssh.exe start? 2. I increased the elay between successive login attempts to 6 seconds and kts-ini.log doesn't have the overlap between sessions. However, the output on the console still seems to have spurious newlines periodically. Is there a way to log all the output that the Kpym server will send to the client just before it does? These are all on Windows Vista. thanks for all the help. -sr
Kroum Grigorov		Jun 11 2008 18:19

1. I'm using telnet. Why does term-ssh.exe start? This is a typo in the log function, if you are connecting via telnet then KTS is running in telnet mode only. 2. kts-ini.log doesn't have the overlap between sessions I dont think the session overlap is your problem. The sessions run in separate processes and there is no way to mix the session's output unless you mix them in your client(and I doubt that is the case) 3. the output on the console still seems to have spurious newlines periodically This is "normal" as KTS was generally developped to be used with full featured telnet clients. That means that it might periodically send telnet control secuances that are perfectly valid for telnet clients but might be really hard to script. You can try to add some "control" string that tells your expect script that some "controll point" was reached. For example you could have something like: echo script_part_1_reached echo script_part_1_reached echo script_part_1_reached and wait for "script_part_1_reached" in your expect script as a marker that certain part of the script is reached. Note that the "control string" is reapeated 3 times thus increasing the chance for your expect script to recognize it. 4. Notice that disconnect was done at 9:2:37, while the session ended at 9:2:41 - a 4 second delay. There's certain time needed by the session to shut down properly. I believe there are ways to optimize the code and decrease this delay, but since there's little or no impact on the overall performance I will probably leave this. 5. Is there a way to log all the output that the Kpym server will send to the client just before it does? No, but if you need the session output only without the "scripting" part you can tell your telnet client to log the session in a file. I think you can do this with the "-f" switch of the standart telnet.exe program Kroum Kroum
sr		Jun 18 2008 21:03

Hi Kroum, Thanks much for the responses. I am using ActiveStates tcl/Expect to do the scripting. And as you rightly pointed out, not being a full featured telnet client, it is getting confused. The most confusion seems to be from the positioning commands that the Kpym Telnet server sends. Peeking at the code, it seems that the KSession::naws is generates the positioning characters. I am in the process of trying to compile the code without these and trying things out. But do you see any problems with just removing the calls to this function in KSession::ProxyCommunicationLoop from the server end? Thanks, -sr
Kroum Grigorov		Jun 30 2008 12:55

> Peeking at the code, it seems that the KSession::naws is generates the positioning characters The naws command generates the telent NAWS command that is used to synchronise the client and the server screen size. I think you can remove this, but you will have to test this yourself. Besides, there are more telnet control codes in KTelnet.hxx in GotoXY and Color functions, if you plan to use KTS only with your expect script you might try to change these functions too(I think you can just make them to return empty string) Kroum