From mboxrd@z Thu Jan 1 00:00:00 1970 X-Spam-Checker-Version: SpamAssassin 3.4.4 (2020-01-24) on polar.synack.me X-Spam-Level: X-Spam-Status: No, score=-1.9 required=5.0 tests=BAYES_00 autolearn=ham autolearn_force=no version=3.4.4 X-Google-Thread: 103376,8da181ade72859cf,start X-Google-Attributes: gid103376,public X-Google-Language: ENGLISH,ASCII-7-bit From: Brian May Newsgroups: comp.lang.ada Subject: timeouts Date: Thu, 19 Aug 2004 09:46:49 +1000 Message-ID: User-Agent: Gnus/5.1006 (Gnus v5.10.6) Emacs/21.3 (gnu/linux) Cancel-Lock: sha1:Mb1nko+Bt5Q4nc9Wb3dJMbd6jbA= MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii NNTP-Posting-Host: dsl-202-173-153-89.vic.westnet.com.au X-Trace: news.melbourne.pipenetworks.com 1092872808 202.173.153.89 (19 Aug 2004 09:46:48 +1000) X-Complaints-To: abuse@pipenetworks.com X-Abuse-Info: Please forward all headers to enable your complaint to be properly processed. Path: g2news1.google.com!news1.google.com!newsfeed.stanford.edu!logbridge.uoregon.edu!newsfeeds.ihug.co.nz!ihug.co.nz!news.xtra.co.nz!news.mel.connect.com.au!birrie.connect.com.au!news.alphalink.com.au!news.melbourne.pipenetworks.com!not-for-mail Xref: g2news1.google.com comp.lang.ada:2823 Date: 2004-08-19T09:46:49+10:00 List-Id: Hello, I have a written a communications protocols, for Windows, in Ada, using the GNAT compiler for Windows. This is my attempt at implementing the MAP27 protocol (used for talking to trunk radios). The main protocol is implemented as a separate task along the lines of the following code. This code is simplified from my actual code, and only shows the what I consider relevant to this bug, based on print messages. Any mistakes in syntax are probably copy errors. I should be able to provide full code on request, but need to confirm this first. task body State_Machine_Task is timer_enabled : Boolean := True; expire_time : Duration := clock + 0.1; ... begin ... Put(Log.Debug,"----------------------------------------"); Put(...); Put(timer_enabled,expire_time); Put(...); while Continue loop case SMT.DTE_State is when ... => select accept ... ... or ... or when timer_enabled => delay until expire_time; print ("In.Link_Establishment_Timeout"); expire_time := clock + 0.1; end select; when ... => ... ... end case; end loop; end; Generally speaking, the program does all this fine, and constantly prints the expired message, as required. However, occasionally something goes wrong, and while it prints the expiration time OK, it takes ages to print the "expired" message. e.g. one occasion the event was 7 hours late. This puzzles me, because every time the timer is incremented by 0.1 seconds, and my understanding is that the timer should trigger if the current time is greater then the expiration time. To be precise, at 1:50:57 am the timer was incremented, and the select reentered, and at 9:12:59 the timer expired. The actual log produced is below: 1:50:57 DLL DEBUG Activity_Timer: disabled 1:50:57 DLL DEBUG Link_Failure_Detection_Timer: disabled 1:50:56 DLL DEBUG In.Link_Establishment_Timeout 1:50:56 DLL DEBUG Out.Link_Request( 14, 1, 1) 1:50:56 T50 DEBUG TX Packet Packet( 22 16 2 1 14 1 1 16 3 138 9 ) 1:50:57 DLL DEBUG Out.Link_Request return 1:50:57 DLL DEBUG ---------------------------------------- 1:50:57 DLL DEBUG looping state=RESET_WAIT 1:50:57 DLL DEBUG Link_Establishment_Timer time 1:50:57 1:50:57 DLL DEBUG Retry_Timer: disabled 1:50:57 DLL DEBUG Acknowledgement_Timer: disabled 1:50:57 DLL DEBUG Activity_Timer: disabled 1:50:57 DLL DEBUG Link_Failure_Detection_Timer: disabled 9:12:59 DLL DEBUG In.Link_Establishment_Timeout 9:12:59 DLL DEBUG Out.Link_Request( 14, 1, 1) 9:12:59 T50 DEBUG TX Packet Packet( 22 16 2 1 14 1 1 16 3 138 9 ) 9:12:59 DLL DEBUG Out.Link_Request return 9:12:59 DLL DEBUG ---------------------------------------- 9:12:59 DLL DEBUG looping state=RESET_WAIT 9:12:59 DLL DEBUG Link_Establishment_Timer time 9:12:59 9:12:59 DLL DEBUG Retry_Timer: disabled 9:12:59 DLL DEBUG Acknowledgement_Timer: disabled 9:12:59 DLL DEBUG Activity_Timer: disabled 9:12:59 DLL DEBUG Link_Failure_Detection_Timer: disabled The fact that the time decrements from 57 seconds to 56 seconds seems weird in itself. It could be due to some obscure round of error in my code to print the time, but I can't imagine where this would occur. In all cases the current value of Clock is used, and it isn't stored anywhere. Or it could be some sort of time synchronisation tool on the computer, I am not aware of anything like this though. During this wait, all evidence points to the fact that the timer_enabled and expire_time variables are correct, they cannot be changed from other tasks, and that it was waiting in the select statement. During this time, the task appears to respond to other select events fine. I haven't yet tested if the timeout starts working again after entering the select again, as the structure of the code doesn't make this easy. What is going on? Strict real-time behaviour is not required, but 7 hours instead of 0.1 seconds is slightly on the extreme side. Any ideas? Thanks in advance. PS. In hindsight, the "timer_enabled" variable may not be required, as I can use the state variable instead and probably simplify some of the code, but I am skeptical this is causing the problem. -- Brian May