Bug 15006 - Need to distinguish client timeout from login timeout
Summary: Need to distinguish client timeout from login timeout
Status: CLOSED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: SIP2 (show other bugs)
Version: master
Hardware: All All
: P5 - low normal (vote)
Assignee: Colin Campbell
QA Contact: Marcel de Rooy
URL:
Keywords:
Depends on: 13432 13807
Blocks:
  Show dependency treegraph
 
Reported: 2015-10-13 14:17 UTC by Colin Campbell
Modified: 2017-12-07 22:16 UTC (History)
12 users (show)

See Also:
Change sponsored?: ---
Patch complexity: Small patch
Who signed the patch off:
Text to go in the release notes:
Version(s) released in:


Attachments
Proposed Patch (3.62 KB, patch)
2015-11-20 12:47 UTC, Colin Campbell
Details | Diff | Splinter Review
Bug 15006 Sip separate global from login timeouts (3.75 KB, patch)
2015-12-11 08:52 UTC, Frédéric Demians
Details | Diff | Splinter Review
Bug 15006 Sip separate global from login timeouts (3.83 KB, patch)
2015-12-11 10:23 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 15006: [QA Follow-up] Indentation for two subroutines (9.38 KB, patch)
2016-06-17 12:06 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006 Sip separate global from login timeouts (3.88 KB, patch)
2016-06-17 12:07 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Add timeout and strikes to raw_transport (2.77 KB, patch)
2016-06-17 12:26 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Timeout logic in sip_protocol_loop (5.11 KB, patch)
2016-06-17 12:26 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Add timeout and strikes to raw_transport (2.71 KB, patch)
2016-06-24 12:01 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Timeout logic in sip_protocol_loop (5.11 KB, patch)
2016-06-24 12:01 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Add timeout and strikes to raw_transport (2.73 KB, patch)
2016-06-24 12:09 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Timeout logic in sip_protocol_loop (5.11 KB, patch)
2016-06-24 12:10 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [QA Follow-up] Indentation for two subroutines (9.39 KB, patch)
2016-06-24 17:32 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 15006: [QA Follow-up] Indentation for two subroutines (9.39 KB, patch)
2016-06-24 17:32 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 15006 Sip separate global from login timeouts (3.89 KB, patch)
2016-06-24 17:32 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Add timeout and strikes to raw_transport (2.74 KB, patch)
2016-06-24 17:32 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Timeout logic in sip_protocol_loop (5.12 KB, patch)
2016-06-24 17:32 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 15006: [QA Follow-up] Indentation for two subroutines (7.24 KB, patch)
2016-07-01 06:50 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006 Sip separate global from login timeouts (4.09 KB, patch)
2016-07-01 06:50 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Add timeout and strikes to raw_transport (2.77 KB, patch)
2016-07-01 06:50 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [COUNTERPATCH] Timeout logic in sip_protocol_loop (4.46 KB, patch)
2016-07-01 06:50 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: Add timeout and strikes to raw_transport (2.75 KB, patch)
2016-07-01 10:15 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: Centralize timeout logic and allow zero client timeout (11.25 KB, patch)
2016-07-01 10:16 UTC, Marcel de Rooy
Details | Diff | Splinter Review
proposed patch 1 Fix bugs in login procedure (3.59 KB, patch)
2016-07-06 14:52 UTC, Colin Campbell
Details | Diff | Splinter Review
Proposed patch (2.35 KB, patch)
2016-07-06 14:53 UTC, Colin Campbell
Details | Diff | Splinter Review
Rebase of Marcel's earlier patch (11.19 KB, patch)
2016-07-06 14:58 UTC, Colin Campbell
Details | Diff | Splinter Review
Proposed patch (1.77 KB, patch)
2016-07-06 15:03 UTC, Colin Campbell
Details | Diff | Splinter Review
Bug 15006: Introduce client_timeout in SIPconfig.xml (1.96 KB, patch)
2016-07-12 15:04 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: Centralize timeout logic and allow zero client timeout (10.44 KB, patch)
2016-07-12 15:04 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006 Correct indentation of EXPORTs in Sip.pm (1.82 KB, patch)
2016-07-12 15:04 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [QA Follow-up] Satisfy qa tools with one tab less (961 bytes, patch)
2016-07-12 15:04 UTC, Marcel de Rooy
Details | Diff | Splinter Review
[SIGNED-OFF] Bug 15006 Drop raw connection if login fails (3.63 KB, patch)
2016-07-13 00:55 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
[SIGNED-OFF] Bug 15006 Remove tabs from sip_protocol_loop (2.39 KB, patch)
2016-07-13 00:56 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
[SIGNED-OFF] Bug 15006: Introduce client_timeout in SIPconfig.xml (1.96 KB, patch)
2016-07-13 00:57 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
[SIGNED-OFF] Bug 15006: Centralize timeout logic and allow zero client timeout (10.44 KB, patch)
2016-07-13 00:57 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
[SIGNED-OFF] Bug 15006 Correct indentation of EXPORTs in Sip.pm (1.82 KB, patch)
2016-07-13 00:58 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
[SIGNED-OFF] Bug 15006: [QA Follow-up] Satisfy qa tools with one tab less (962 bytes, patch)
2016-07-13 01:00 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
Bug 15006 Drop raw connection if login fails (3.73 KB, patch)
2016-07-13 12:24 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006 Remove tabs from sip_protocol_loop (2.49 KB, patch)
2016-07-13 12:24 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: Introduce client_timeout in SIPconfig.xml (2.01 KB, patch)
2016-07-13 12:24 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: Centralize timeout logic and allow zero client timeout (8.81 KB, patch)
2016-07-13 12:24 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006 Correct indentation of EXPORTs in Sip.pm (1.83 KB, patch)
2016-07-13 12:24 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [QA Follow-up] Satisfy qa tools with one tab less (1008 bytes, patch)
2016-07-13 12:24 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 15006: [QA Follow-up] Only handle login requests in raw_transport (1.43 KB, patch)
2016-07-13 12:24 UTC, Marcel de Rooy
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Colin Campbell 2015-10-13 14:17:01 UTC
Since patch 13432 was applied the main sip loop times out according to the timeout value. This can cause considerable instability and cause client machines to shutdown if the value is too low. As the timeout variable is a login timeout it is typically on the low side (30sec) for client connections it needs to be over 5mins typically possibly more. Suggest a the time out for active connections be separated from the login timeout. we also need the possibility to switch it off completely. Submit a  patch adding a 'client_timeout' parameter
Comment 1 Colin Campbell 2015-11-20 12:47:16 UTC Comment hidden (obsolete)
Comment 2 Frédéric Demians 2015-11-25 15:27:17 UTC
With this:

my $timeout = $self->{service}->{client_timeout} || $config->{client_timeout};

what will happen after Koha upgrade if a library doesn't add the new 'client_timeout' parameter to its config file. Wouldn't it be better to have something like:

my $timeout = $self->{service}->{client_timeout} || $config->{client_timeout} || 
              $self->{service}->{timeout} || $config->{timeout};

And/or a note via updatabase.pl to notify that SIP config file has to be reviewed after upgrade.
Comment 3 Colin Campbell 2015-12-09 10:31:15 UTC
(In reply to Frédéric Demians from comment #2)
> With this:
> 
> my $timeout = $self->{service}->{client_timeout} ||
> $config->{client_timeout};
> 
> what will happen after Koha upgrade if a library doesn't add the new
> 'client_timeout' parameter to its config file. Wouldn't it be better to have
> something like:
> 
> my $timeout = $self->{service}->{client_timeout} ||
> $config->{client_timeout} || 
>               $self->{service}->{timeout} || $config->{timeout};
> 
> And/or a note via updatabase.pl to notify that SIP config file has to be
> reviewed after upgrade.

If the client_timeout is not present the current situation remains the same (or in fact reverts to the situation before timeout was incorrectrly extended to timeout active connections) Your suggestions for adding it to the test preserves the bad code from patch 13432 which has caused in my experience to make previously working installs go unstable. Once this gives a working system, I'm hoping to overhaul the cxonfig file which is under documented
Comment 4 Frédéric Demians 2015-12-11 08:52:55 UTC Comment hidden (obsolete)
Comment 5 Jonathan Druart 2015-12-11 10:23:21 UTC Comment hidden (obsolete)
Comment 6 Kyle M Hall 2015-12-11 15:07:39 UTC
> If the client_timeout is not present the current situation remains the same
> (or in fact reverts to the situation before timeout was incorrectrly
> extended to timeout active connections) Your suggestions for adding it to
> the test preserves the bad code from patch 13432 which has caused in my
> experience to make previously working installs go unstable. Once this gives
> a working system, I'm hoping to overhaul the cxonfig file which is under
> documented

Bug 13432 patched a serious problem where child sip process would never die and thus the SIP server would continue to take up more and more memory until a restart was required to kill all the child processes. I'm fairly certain this patch would bring back that situation. I would like to see a default timeout in the code instead of allowing client_timeout to not be set.
Comment 7 Colin Campbell 2015-12-16 11:57:26 UTC
Bug 13432 does not fix the bug you describe. There is (hard to reproduce in testing but found in practice) bug which is caused by a child failing to receive the kill signal from the parent, or possibly looping on an operation subsequent to a call. Problem arises from the way the protocol loop is coded

This patch will still allow you to timeout a call should you wish but also negate the necessity of reverting 13432 in production because it causes units to fail due to the server timing out valid connections
Comment 8 Kyle M Hall 2015-12-17 11:51:39 UTC
Thanks for the explanation! I'm going to ask Larry to lend some eyes to this. I'm just want to make sure we don't introduce a regression. I think another alternative would be to set the client_timeout to default to the timeout if client_timeout is not defined. You could then use a client_timeout of 0 to specify no timeout at all.
Comment 9 Larry Baerveldt 2015-12-17 17:31:16 UTC
Like Kyle, I am concerned about regression. The issue addressed by Bug 13432 was a very serious one for us, and affected virtually every site using SIP. New child processes were continually being created throughout the day, and older child processes were never dying. In some cases the number of SIP processes would literally max out the RAM. We had to introduce daily restarts of SIP in our crons, and for some sites, even that was not enough. And Bug 13432 DID fix that problem. 

As to the problem of the timeout logic causing dropped connections post 13432, we simply fixed that on our servers by increasing the timeout in the Service and Institution levels to 360. That worked for most SIP vendors. 

That said, I think this patch would be okay if it includes Kyle's suggestion to have the client_timeout default to the timeout if not defined.
Comment 10 Colin Campbell 2015-12-23 11:13:37 UTC
(In reply to Larry Baerveldt from comment #9)
> Like Kyle, I am concerned about regression. The issue addressed by Bug 13432
> was a very serious one for us, and affected virtually every site using SIP.
> New child processes were continually being created throughout the day, and
> older child processes were never dying. In some cases the number of SIP
> processes would literally max out the RAM. We had to introduce daily
> restarts of SIP in our crons, and for some sites, even that was not enough.
> And Bug 13432 DID fix that problem. 
> 
> As to the problem of the timeout logic causing dropped connections post
> 13432, we simply fixed that on our servers by increasing the timeout in the
> Service and Institution levels to 360. That worked for most SIP vendors. 
> 
> That said, I think this patch would be okay if it includes Kyle's suggestion
> to have the client_timeout default to the timeout if not defined.

If you apply the change in bug 15418 do you still see this problem? In Pre-Fork child processes should not die - but my suspicion is that due to the rather awkward way the callback was originally implemented they are not always left in a state ready to be reused. In part to deal with those problems I started using Fork in production and it seems more reliable
Comment 11 Larry Baerveldt 2015-12-23 16:26:20 UTC
We haven't seen the problem (of outrageous growth in number of SIP processes) since Bug 13432 was applied, so there's no way to see if 15418 helps any with that or not. As noted, Bug 13432 solved a very huge problem for us, and any issues with SIP devices timing out was easily solved by adjusting the timeout settings in SIPconfig.xml. We just don't want to see anything that may regress that.
Comment 12 Katrin Fischer 2015-12-27 20:24:18 UTC
I am not sure I fully understand the concerns here. Of course we should take care not to introduce regressions, but wouldn't it be worth taking a deeper look at the problem and seeing if we can improve stability even more?
Comment 13 Kyle M Hall 2016-01-07 16:37:03 UTC
I will try to find some time to run some tests. Here is what I will do:

1) Revert 13432 on master
2) Set up a script that continuously makes sip2 calls via sip_cli_emulator.pl
3) Let that run for a long time
4) Note whether memory usage increases dramatically
5) Apply this patch
6) Repeat steps 2-4
6) Apply bug 15006
7) Repeat steps 2-4

If everything checks out, we should move ahead with this.

Colin, does that seem like a reasonable test plan?
Comment 14 Jonathan Druart 2016-03-11 11:08:18 UTC
ping Colin
Comment 15 Colin Campbell 2016-04-01 14:31:10 UTC
(In reply to Kyle M Hall from comment #13)
> I will try to find some time to run some tests. Here is what I will do:
> 
> 1) Revert 13432 on master
> 2) Set up a script that continuously makes sip2 calls via sip_cli_emulator.pl
> 3) Let that run for a long time
> 4) Note whether memory usage increases dramatically
> 5) Apply this patch
> 6) Repeat steps 2-4
> 6) Apply bug 15006
> 7) Repeat steps 2-4
> 
> If everything checks out, we should move ahead with this.
> 
> Colin, does that seem like a reasonable test plan?

Yes - Would be interested if the same test was run using Netserver::Fork, instead of Netserver::Prefork that should return resources from dead connections (although memory leak may be elsewhere)
Comment 16 Marcel de Rooy 2016-06-17 08:46:57 UTC
QA: Looking here now. Will probably ask some questions first :)
Comment 17 Marcel de Rooy 2016-06-17 12:04:04 UTC
Colin or Kyle:

Well, I have some improvements coming hopefully :) Already wrote some patches.
Few questions are:

Is my impression correct that $config->{timeout} normally does not exist?
We do not have/want[?] such entries in SIPconfig.

Should we only allow login attempts in raw_transport? We do not now. Or should we allow e.g. SC_STATUS messages too?
Comment 18 Marcel de Rooy 2016-06-17 12:06:55 UTC Comment hidden (obsolete)
Comment 19 Marcel de Rooy 2016-06-17 12:07:00 UTC Comment hidden (obsolete)
Comment 20 Marcel de Rooy 2016-06-17 12:07:55 UTC
Please do not change status yet. Not finished..
Comment 21 Marcel de Rooy 2016-06-17 12:26:32 UTC Comment hidden (obsolete)
Comment 22 Marcel de Rooy 2016-06-17 12:26:36 UTC Comment hidden (obsolete)
Comment 23 Marcel de Rooy 2016-06-17 12:28:35 UTC
I would appreciate feedback on the questions raised earlier.
The counterpatches can be applied on top of the first two.
See the restricted handling in the third patch of only logins.
And the policy/timeout use in the fourth patch.

We should remove some changes to the xml again and add a simple test.
Comment 24 Marcel de Rooy 2016-06-24 12:01:52 UTC Comment hidden (obsolete)
Comment 25 Marcel de Rooy 2016-06-24 12:01:56 UTC Comment hidden (obsolete)
Comment 26 Marcel de Rooy 2016-06-24 12:04:26 UTC
Decided to relax the restricted handling in the third patch here.
Could be done on another report if we wish to.

Still want some feedback on using $server->{policy}->{timeout} in the fourth patch. How do sip2 machines generally respond to that parameter if they do?
Comment 27 Marcel de Rooy 2016-06-24 12:09:56 UTC Comment hidden (obsolete)
Comment 28 Marcel de Rooy 2016-06-24 12:10:01 UTC Comment hidden (obsolete)
Comment 29 Kyle M Hall 2016-06-24 17:32:04 UTC Comment hidden (obsolete)
Comment 30 Kyle M Hall 2016-06-24 17:32:34 UTC Comment hidden (obsolete)
Comment 31 Kyle M Hall 2016-06-24 17:32:41 UTC Comment hidden (obsolete)
Comment 32 Kyle M Hall 2016-06-24 17:32:44 UTC Comment hidden (obsolete)
Comment 33 Kyle M Hall 2016-06-24 17:32:47 UTC Comment hidden (obsolete)
Comment 34 Kyle M Hall 2016-06-24 17:33:37 UTC
I like this proposal, but I think we should get Colin's testing and input before setting it to Passed QA.
Comment 35 Kyle M Hall 2016-06-24 17:45:15 UTC
Marcell, would you be able to rebase these patches on top of bug 13807?
Comment 36 Martin Renvoize 2016-06-28 10:58:42 UTC
(In reply to Kyle M Hall from comment #34)
> I like this proposal, but I think we should get Colin's testing and input
> before setting it to Passed QA.

I'll try setting up some tests
Comment 37 Colin Campbell 2016-06-30 10:33:12 UTC
(In reply to Kyle M Hall from comment #34)
> I like this proposal, but I think we should get Colin's testing and input
> before setting it to Passed QA.

It was me saying I'll test --- I was masquerading as Martin
Comment 38 Marcel de Rooy 2016-06-30 10:38:35 UTC
(In reply to Colin Campbell from comment #37)
> (In reply to Kyle M Hall from comment #34)
> > I like this proposal, but I think we should get Colin's testing and input
> > before setting it to Passed QA.
> 
> It was me saying I'll test --- I was masquerading as Martin

Secure passwords :) Thx. Could you also have a look at comment26 ?
Comment 39 Colin Campbell 2016-06-30 11:05:23 UTC
(In reply to Marcel de Rooy from comment #22)
> Created attachment 52480 [details] [review] [review]
> Bug 15006: [COUNTERPATCH] Timeout logic in sip_protocol_loop
> 
> Instead of adding yet another client timeout, I propose to use the
> policy timeout that we also communicate in send_acs_status.
> Although I agree that we perhaps better move it from institution to
> account/login level, this c/should be done on another report. We
> may have issues with existing configurations.
> 
> In order to find a compromise between bug 13432 and the originally
> proposed 15006 patch, this patch allows you to put a zero in the
> policy timeout entry in the SIPconfig.
> 
> The timeout logic is moved to a Sip.pm subroutine. Will add a test :)
> 
> Test plan:
> [1] Check timeout after login with policy/timeout > 0.
> [2] Check timeout after login with policy/timeout = 0. (No timeout!)
> [3] Check timeout after login with no policy timeout. Fallback to service.
> [4] Check timeout after login with no policy and service timeout.
>     Should fallback to 30 seconds for both login process and after login.
> 
> Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>

A problem is the timeout send back in acs_status is a transaction timeout. Strictly when that timeout elapses the client sould revert the current transaction but the connection should be maintained. There is of course already a timeout on the connection at tcp level if you are using keep alives
Comment 40 Marcel de Rooy 2016-06-30 11:16:43 UTC
(In reply to Colin Campbell from comment #39)
> A problem is the timeout send back in acs_status is a transaction timeout.
> Strictly when that timeout elapses the client sould revert the current
> transaction but the connection should be maintained. There is of course
> already a timeout on the connection at tcp level if you are using keep alives

OK That is clear. So we indeed need another one.
This transaction timeout could perhaps be placed at a more logical place in the config?
Comment 41 Marcel de Rooy 2016-07-01 06:50:34 UTC Comment hidden (obsolete)
Comment 42 Marcel de Rooy 2016-07-01 06:50:40 UTC Comment hidden (obsolete)
Comment 43 Marcel de Rooy 2016-07-01 06:50:44 UTC Comment hidden (obsolete)
Comment 44 Marcel de Rooy 2016-07-01 06:50:48 UTC Comment hidden (obsolete)
Comment 45 Marcel de Rooy 2016-07-01 06:53:31 UTC
(In reply to Kyle M Hall from comment #35)
> Marcel, would you be able to rebase these patches on top of bug 13807?

I did now. But in view of Colin's comments I will still have a look on the last patch. Working on it..
Comment 46 Marcel de Rooy 2016-07-01 10:15:55 UTC Comment hidden (obsolete)
Comment 47 Marcel de Rooy 2016-07-01 10:16:00 UTC Comment hidden (obsolete)
Comment 48 Marcel de Rooy 2016-07-01 10:17:11 UTC
Kyle: Please verify your signoff. Thanks.
Comment 49 Colin Campbell 2016-07-01 14:25:43 UTC
Comment on attachment 53013 [details] [review]
Bug 15006: Add timeout and strikes to raw_transport

This is unnecessary - The bogus 3 strikes was already removed in commit  078ce11e113b172726f9ab3180e52a06334d4aab


Test plan is ambiguous this routine is not called when using "telnet" authentication. On a raw connection session is started when a sip login is received. If that login fails, the session is terminated. (The login is from the client machine's config so it wont try again with different values) and sends a failed login response before shutting down. If the input is not a login message or a random string it does not respond or login the session but falls through to sip_protocol_loop and times out on the time out set there. I think this should be considered a bug. Its probably the reason why adding a timeout to that had an effect on building up sip sessions as that is meant to be an endless (until logout or connection drop) loop - I think this a bug and that if a connection is not established raw_transport should exit without entering sip_loop
Comment 50 Colin Campbell 2016-07-01 14:39:47 UTC
I'll try and tidyup the way login on raw connections handles poor connections. The changes introduced in 13432 was a major regression for us and were no longer using the standard SIPServer.pm as many sites are dependent on large numbers of SIP connections. I'll see if that can all pull together in one patch. I'm resetting the status for the moment
Comment 51 Marcel de Rooy 2016-07-01 14:55:19 UTC
(In reply to Colin Campbell from comment #49)
> Comment on attachment 53013 [details] [review] [review]
> Bug 15006: Add timeout and strikes to raw_transport
> 
> This is unnecessary - The bogus 3 strikes was already removed in commit 
> 078ce11e113b172726f9ab3180e52a06334d4aab
> 
> 
> Test plan is ambiguous this routine is not called when using "telnet"
> authentication. On a raw connection session is started when a sip login is
> received. If that login fails, the session is terminated. (The login is from
> the client machine's config so it wont try again with different values) and
> sends a failed login response before shutting down. If the input is not a
> login message or a random string it does not respond or login the session
> but falls through to sip_protocol_loop and times out on the time out set
> there. I think this should be considered a bug. Its probably the reason why
> adding a timeout to that had an effect on building up sip sessions as that
> is meant to be an endless (until logout or connection drop) loop - I think
> this a bug and that if a connection is not established raw_transport should
> exit without entering sip_loop

From testing i recall seeing that raw_transport does respond to requests; one of the reasons that I made it more restrict in a previous patch (relaxed it later again for minimal behavior changes).
Comment 52 Colin Campbell 2016-07-05 09:45:26 UTC
(In reply to Marcel de Rooy from comment #51)
> (In reply to Colin Campbell from comment #49)
> > Comment on attachment 53013 [details] [review] [review] [review]
> > Bug 15006: Add timeout and strikes to raw_transport
> > 
> > This is unnecessary - The bogus 3 strikes was already removed in commit 
> > 078ce11e113b172726f9ab3180e52a06334d4aab
> > 
> > 
> > Test plan is ambiguous this routine is not called when using "telnet"
> > authentication. On a raw connection session is started when a sip login is
> > received. If that login fails, the session is terminated. (The login is from
> > the client machine's config so it wont try again with different values) and
> > sends a failed login response before shutting down. If the input is not a
> > login message or a random string it does not respond or login the session
> > but falls through to sip_protocol_loop and times out on the time out set
> > there. I think this should be considered a bug. Its probably the reason why
> > adding a timeout to that had an effect on building up sip sessions as that
> > is meant to be an endless (until logout or connection drop) loop - I think
> > this a bug and that if a connection is not established raw_transport should
> > exit without entering sip_loop
> 
> From testing i recall seeing that raw_transport does respond to requests;
> one of the reasons that I made it more restrict in a previous patch (relaxed
> it later again for minimal behavior changes).

Been doing some extensive testing and the raw_transport routine going some things very differently than I think we all imagine. Will post the patch when final element merged. We need the timeout to escape the while if anyone can engineer us into an infinite loop there (I've not been able to do that ...but..)
Comment 53 Colin Campbell 2016-07-06 14:52:40 UTC Comment hidden (obsolete)
Comment 54 Colin Campbell 2016-07-06 14:53:42 UTC Comment hidden (obsolete)
Comment 55 Colin Campbell 2016-07-06 14:58:54 UTC Comment hidden (obsolete)
Comment 56 Colin Campbell 2016-07-06 15:03:57 UTC Comment hidden (obsolete)
Comment 57 Colin Campbell 2016-07-06 15:09:58 UTC
I've now submitted a series of 4 patches, including a rebase of Marcel's timeout changes. The main logic changes are all in the first which fixes the flaw in the raw_transport logic that causes bad/failed connections to drop into the sip_protocol_loop thus necessitating timing out.

The patches assume that the patch for Bug 13807 has been applied
Comment 58 Srdjan Jankovic 2016-07-12 02:31:41 UTC
If get_timeout() works on SIPServer object, why is it not a SIPServer method?
Comment 59 Marcel de Rooy 2016-07-12 12:00:28 UTC
(In reply to Srdjan Jankovic from comment #58)
> If get_timeout() works on SIPServer object, why is it not a SIPServer method?

I wouldn't mind moving it there.
But since it is more a utility thing, looking in the server data just like e.g. Sip::maybe_add looks at server accout info, I dropped it in Sip.pm.

Will move it.
Comment 60 Marcel de Rooy 2016-07-12 12:09:39 UTC
(In reply to Marcel de Rooy from comment #59)
> (In reply to Srdjan Jankovic from comment #58)
> > If get_timeout() works on SIPServer object, why is it not a SIPServer method?
> 
> I wouldn't mind moving it there.
> But since it is more a utility thing, looking in the server data just like
> e.g. Sip::maybe_add looks at server accout info, I dropped it in Sip.pm.
> 
> Will move it.

On second thougth, I would rather not move it. Using SIPServer in MsgType does not seem to be a good idea. Rather leave this as-is now.
Comment 61 Marcel de Rooy 2016-07-12 15:04:24 UTC Comment hidden (obsolete)
Comment 62 Marcel de Rooy 2016-07-12 15:04:30 UTC Comment hidden (obsolete)
Comment 63 Marcel de Rooy 2016-07-12 15:04:34 UTC Comment hidden (obsolete)
Comment 64 Marcel de Rooy 2016-07-12 15:04:39 UTC Comment hidden (obsolete)
Comment 65 Marcel de Rooy 2016-07-12 15:24:02 UTC
Srdjan: If you could add a signoff, this would probably allow me to pass qa on this patch set.
Comment 66 Marcel de Rooy 2016-07-12 15:27:39 UTC
Hmm Colin: Raw_transport only may still respond to a 97 request.
But is that response always correct, or from an older session or so?
Comment 67 Srdjan Jankovic 2016-07-13 00:55:37 UTC Comment hidden (obsolete)
Comment 68 Srdjan Jankovic 2016-07-13 00:56:21 UTC Comment hidden (obsolete)
Comment 69 Srdjan Jankovic 2016-07-13 00:57:01 UTC Comment hidden (obsolete)
Comment 70 Srdjan Jankovic 2016-07-13 00:57:43 UTC Comment hidden (obsolete)
Comment 71 Srdjan Jankovic 2016-07-13 00:58:29 UTC Comment hidden (obsolete)
Comment 72 Srdjan Jankovic 2016-07-13 01:00:03 UTC Comment hidden (obsolete)
Comment 73 Srdjan Jankovic 2016-07-13 01:03:46 UTC
I still think that

$server->get_timeout({})
$self->get_timeout({})

beats

C4::SIP::Sip::get_timeout($server, {})
C4::SIP::Sip::get_timeout($self, {})
Comment 74 Marcel de Rooy 2016-07-13 08:26:48 UTC
(In reply to Srdjan Jankovic from comment #73)
> I still think that
> 
> $server->get_timeout({})
> $self->get_timeout({})
> 
> beats
> 
> C4::SIP::Sip::get_timeout($server, {})
> C4::SIP::Sip::get_timeout($self, {})

Thx Srdjan for testing.
Of course, you are right. Only problem is I need to mock some SIPServer stuff to still have a working unit test.
Patch forthcoming.
Comment 75 Marcel de Rooy 2016-07-13 12:24:12 UTC
Created attachment 53363 [details] [review]
Bug 15006 Drop raw connection if login fails

raw_connection was not behaving correctly if an invalid string was
passed or a login failed.
It was not checking that the login succeeded ( it checked that account
existed not that it contained data and it existed even if login failed)
and so failed logins instead of aborting immediately fell through into
the sip_protocol_loop, forcing that to timeout invalid connections.
It now checks that account has id set and returns if not.

The timeout alarm is now set on the while loop, in normal running this
should not be triggered as the socket is opened and the first data
should be a login message and the while loop should only iterate once,
but lets not go into an infinite loop due to unforeseen circumstances.

I have reindented the routine as the flow was not clear (the while was
not indented at all.

Also if using Net::Server::PreFork when a new connection comes in you
may be handed the the successful login parameters from a preceding call.
Because of this you could successfully transmit transactions and Koha
would carry them out without having received a valid login ( and
possibly with the wrong account details!) We now delete any existing
account for new connections.

NB: This patch requires that the patch for bug 13807 has been applied

Signed-off-by: Srdjan <srdjan@catalyst.net.nz>
Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 76 Marcel de Rooy 2016-07-13 12:24:17 UTC
Created attachment 53364 [details] [review]
Bug 15006 Remove tabs from sip_protocol_loop

Remove the tabs causing inconsistent indentation
of sip_protocol_loop and replace with spaces

Reimplements the renaining parts of Marcel de Rooy's
original QA patch

No logic changes in this patch - layout only

Signed-off-by: Srdjan <srdjan@catalyst.net.nz>
Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 77 Marcel de Rooy 2016-07-13 12:24:22 UTC
Created attachment 53365 [details] [review]
Bug 15006: Introduce client_timeout in SIPconfig.xml

Most selfchecks have persistent connections and send a
periodic status request at intervals (approx every 5mins appears
the norm) The timeout was dropping connections by default every 30secs
which for the client appears as a very flakey network.

This patch adds a separate parameter client_timeout that can be
used if you do want to force a disconnect if the client sends
no requests for a period. The sample config sets it to 600, but you
can also define a 0 value meaning no timeout. If the parameter is not
defined, it will fallback to service timeout.

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Restored this patch from Colin in order to separate it from the
get_timeout patch. Adjusted the commit message slightly.
The original value of 600 from Colin's earlier patch may give less
discussion than setting to 0 (no timeout) in a later proposal.

Signed-off-by: Srdjan <srdjan@catalyst.net.nz>
Comment 78 Marcel de Rooy 2016-07-13 12:24:27 UTC
Created attachment 53366 [details] [review]
Bug 15006: Centralize timeout logic and allow zero client timeout

Moving timeout logic to one routine (with unit test).

This further implements two suggestions from Kyle and Larry:

[1] You could use a client_timeout of 0 to specify no timeout at all.
[2] Have the client_timeout default to the timeout if not defined.

Test plan:
[1] Run t/db_dependent/SIP/SIPServer.t.
[2] Test login timeout for raw and telnet.
[3] Check ACS status message for timeout value. Should match policy
    timeout from institution.
[4] Test client timeout (zero and non-zero).
[5] Remove client timeout. Test fallback to service.
[6] Remove service timeout too. Test fallback to 30 at login.

Signed-off-by: Srdjan <srdjan@catalyst.net.nz>

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Amended to incorporate Srdjan's suggestion to move get_timeout to
SIPServer.pm; this requires some additional mocking in the unit test.
And even makes the test db dependent, as documented.
Comment 79 Marcel de Rooy 2016-07-13 12:24:31 UTC
Created attachment 53367 [details] [review]
Bug 15006 Correct indentation of EXPORTs in Sip.pm

Removed tabs and used spaces consistently
Used 'use base' to remove unnecessary BEGIN sub and
explicit setting of ISA at application level

Signed-off-by: Srdjan <srdjan@catalyst.net.nz>
Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 80 Marcel de Rooy 2016-07-13 12:24:36 UTC
Created attachment 53368 [details] [review]
Bug 15006: [QA Follow-up] Satisfy qa tools with one tab less

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Signed-off-by: Srdjan <srdjan@catalyst.net.nz>
Comment 81 Marcel de Rooy 2016-07-13 12:24:41 UTC
Created attachment 53369 [details] [review]
Bug 15006: [QA Follow-up] Only handle login requests in raw_transport

Although mainly hypothetical, it would still be possible to get
response from the server for an acs resend request. (This exception
is allowed in MsgType::handle.)
I also noticed that the response may well be a message from an older
session still.
This patch just removes that exception by only passing login requests
to sub handle in the raw_transport loop.

Test plan:
[1] Verify normal login procedure for raw.
[2] Check a few acs resend requests in raw. They should terminate without
    a response.

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 82 Marcel de Rooy 2016-07-13 12:30:23 UTC
QA Comment:
Taking the liberty to pass QA on this patch set now and granting Kyle the privilege of having a last look, in view of history and extensive attention given by several involved.
In the fourth patch get_timeout is moved to SIPServer after all (thx to Srdjan); the last small follow-up just cares about a hypothetical first acs resend request.
Comment 83 Kyle M Hall 2016-07-15 14:12:01 UTC
Looks good! Pushed to master for 16.11! Thanks Colin, Marcel!
Comment 84 Frédéric Demians 2016-08-01 09:51:08 UTC
I'm about to push this patch on 16.05 branch (with 13807). But what about 'client_timeout' SIPconfig.xml new parameter. Isn't it necessary to display a warning to admin upgrading the stable branch, in order to advice him/her to tweak its SIP configuration?
Comment 85 Marcel de Rooy 2016-08-01 10:00:04 UTC
(In reply to Frédéric Demians from comment #84)
> I'm about to push this patch on 16.05 branch (with 13807). But what about
> 'client_timeout' SIPconfig.xml new parameter. Isn't it necessary to display
> a warning to admin upgrading the stable branch, in order to advice him/her
> to tweak its SIP configuration?

It falls back to the service timeout if it is not present. If you do not have problems, there may be no direct need to add this parameter.
But printing a line to notify a sysadmin about this option would be fine of course.
Comment 86 Frédéric Demians 2016-08-01 13:37:55 UTC
Pushed in 16.05. Will be in 16.05.02.
Comment 87 Julian Maurice 2016-08-17 10:22:42 UTC
Patches pushed to 3.22.x, will be in 3.22.10