Page 1 of 2
Realtime.txt update behaviour
Posted: Fri 03 Apr 2015 6:43 pm
by PaulMy
Over the past weeks I have tried and changed my realtime interval at 5, 10, 15 and 20 secs as it appeared as realtime.txt was not updating at the set interval. While trying another user's Cumulus realtime and tags php scripts is has become obvious that realtime is updated on my webserver at 20 sec regardless if my settings in Cumulus are 5, 10, 15 or 20 sec.
Using the
http://www.komokaweather.com/weather/resltime.txt url and reloading frequently I see the realtime.txt times as -
hh:mm:52 hh:mm:12 hh:mm:32 hh:mm52 etc. all at 20 second time changes and that is the same whether interval is set at 5, 10, 15 or 20 secs.
The strange part though is that the actual time between the update time (mentally counting by 1-1000 2-1000 3-1000 is usually 10 to 15 sec for 2 counts for realtime to update and then 30+ seconds until the 3rd realtime update, and then another cycle of 10-15 sec and more than 30 sec, and on the same way. I cannot be precise by such seconds counting, but close, and certainly the first 2 are quicked and the 3rd change is much longer. But the time on the realtime.txt string is always at 20 second interval over whatever period it is being observed.
If I set Cumulus at 30 secs for realtime interval then the realtime.txt string time changes at every 30 secs.
Not any issue with displaying data on my website as very little changes in those few seconds other than the scripts that have a counter for realtime or next update then appear to be off of the stated next update.
Anyone have any thoughts what could be causing this?
Paul
Re: Realtime.txt update behaviour
Posted: Sat 04 Apr 2015 7:41 am
by mcrossley
Paul, how long does it take to upload your real time files? If it takes 20 seconds then you will never be able to update them faster than that. You need to look at the real time FTP log.
Re: Realtime.txt update behaviour
Posted: Sat 04 Apr 2015 12:38 pm
by PaulMy
Thanks Mark,
I've had a quick look there and will need some time to understand the times. Will look at that early in the week as just heading out for the long weekend - grandkids time!
Paul
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 2:47 am
by PaulMy
Hi Mark,
Again thanks for mentioning the realtimeftplog file. The time from "Start of realtime FTP" to "End of realtime FTP" is mostly 15.00x seconds when Cumulus Realtime interval is set at 10 seconds, and 20.0xx when interval set at 20 seconds. The time from "Start of realtime FTP" and the next "Start of realtime FTP' is mostly 20.0xx seconds in both 10 sec and 20 sec interval setting (about 5 sec between End and next Start when set at 10 seconds interval).
In addition to realtime.txt I have 4 additional files being processed and uploaded at realtime, and a further 21 additional files processed and uploaded at the 5 minute normal Cumulus upload (in addition to the Cumulus standard files). From looking at the realtimelog it appears that each of those 21 additional files get processed at the realtime interval but not uploaded at that time, only at the normal Cumulus interval. This additional files processing takes some time so that about 15 seconds expire before the "End of Realtime FTP" and the next "Start of realtime FTP".
I have now compromised and set realtime interval at 15 seconds.
It has been a good process to understand the uploads better!
Paul
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 4:56 am
by BCJKiwi
Have just checked ftp logging and also find some tag files in there even though they are definitely NOT set for realtime.
Is this the way it is supposed to be??
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 7:25 am
by steve
BCJKiwi wrote:Have just checked ftp logging and also find some tag files in there even though they are definitely NOT set for realtime.
Is this the way it is supposed to be??
Sorry, I don't understand, please clarify. Are you saying that Cumulus is
actually processing some files (i.e. creating files with data in them) every realtime update even though they are not set for realtime update?
The ftp log may show that it's considering the file for conversion, but if realtime is not set, it shouldn't
actually be processing them (i.e. converting templates to files with data in them) at that time. The way to tell is to look at the timestamps on the processed files.
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 12:30 pm
by BCJKiwi
This is C1 we are discussing here, not MX
Here is one cycle of realtimeftplog.txt. It takes around 6 seconds (realtime interval is 15 secs.)
It shows entries like;
Processing /httpdocs/weather/CUtags.php
That is the destination file, the source file in C:\Cumulus\web is;
CUtagsT.txt
The CUtagsT.txttmp file time stamp is on the Tag processing time, not realtime so it may not actually be processed.
The issue for PaulMy is that he has a lot more files showing in his log and the time for the corresponding cycle is 15.0xx secs where he had a realtime interval of 5 secs and has now changed it to 15 secs but there is still a risk some may be missed.
Code: Select all
16:39:14:653 ========= Start of realtime FTP ==========
16:39:14:654 ===End of upload of realtime.txt
16:39:14:654 ===Processing /httpdocs/weather/CUtags.php
16:39:14:655 ===Processing /httpdocs/wxshare/cloudbaseCU.txt
16:39:14:678 04208E90 TriggerDataSent 1180
16:39:14:690 >|200 Type set to A|
16:39:15:655 Putting file
16:39:15:655 ! HighLevelAsync 0
16:39:15:655 04208E90 TriggerDataSent 1180
16:39:15:691 >|227 Entering Passive Mode (210,5,50,131,176,196).|
16:39:15:691 ! HighLevelAsync 0
16:39:15:692 04209650 Socket handle created 1244
16:39:15:692 TWSocket will connect to 210.5.50.131:45252
16:39:15:726 ! Data Session opened (Put)
16:39:15:727 04209650 TriggerDataSent 1244
16:39:15:727 04208E90 TriggerDataSent 1180
16:39:15:763 >|150 Opening ASCII mode data connection for /httpdocs/wxshare/cloudbaseCU.txttmp|
16:39:15:763 ! Send first block
16:39:15:763 DataSocketPutDataSent 86
16:39:15:763 04209650 TriggerDataSent 1244
16:39:15:763 DataSocketPutDataSent 0
16:39:15:763 04209650 TCustomWSocket.Shutdown 1 1244
16:39:15:799 >|226 Transfer complete|
16:39:15:799 ! Next3PutAsync
16:39:15:800 ! Data Session closed
16:39:15:800 ! Next3PutAsync
16:39:15:800 ! HighLevelAsync 0
16:39:15:800 ! HighLevelAsync done
16:39:15:800 04209650 TCustomWSocket.Shutdown 1 1244
16:39:16:842 Putting done
16:39:16:842 Renaming file
16:39:16:842 ! HighLevelAsync 0
16:39:16:851 04208E90 TriggerDataSent 1180
16:39:16:886 >|350 File or directory exists, ready for destination name|
16:39:16:886 ! HighLevelAsync 0
16:39:16:887 04208E90 TriggerDataSent 1180
16:39:16:922 >|250 Rename successful|
16:39:16:922 ! HighLevelAsync 0
16:39:16:922 ! HighLevelAsync done
16:39:17:848 Renaming done
16:39:17:848 ===Processing /httpdocs/wxshare/davcon24.txt
16:39:17:848 ===Processing /httpdocs/wxshare/sagerCWtags.php
16:39:17:848 ===Processing /httpdocs/weather/rss-feed.php
16:39:17:848 ===Processing /httpdocs/wxshare/davconfcst.php
16:39:17:848 ===Processing C:\Cumulus\web\davcon24.txt
16:39:17:848 ===Processing C:\Cumulus\web\betel_datasummaryCU.php
16:39:17:848 ===Processing C:\Cumulus\web\cumulusrsslocal.php
16:39:17:848 ===Processing C:\Cumulus\web\realtimetags.php
16:39:17:848 ===Processing /httpdocs/wxshare/realtimegauges.txt
16:39:17:849 04208E90 TriggerDataSent 1180
16:39:17:883 >|200 Type set to A|
16:39:18:849 Putting file
16:39:18:849 ! HighLevelAsync 0
16:39:18:849 04208E90 TriggerDataSent 1180
16:39:18:884 >|227 Entering Passive Mode (210,5,50,131,177,40).|
16:39:18:884 ! HighLevelAsync 0
16:39:18:884 04209650 Socket handle created 1256
16:39:18:884 TWSocket will connect to 210.5.50.131:45352
16:39:18:922 ! Data Session opened (Put)
16:39:18:922 04209650 TriggerDataSent 1256
16:39:18:922 04208E90 TriggerDataSent 1180
16:39:18:957 >|150 Opening ASCII mode data connection for /httpdocs/wxshare/realtimegauges.txttmp|
16:39:18:957 ! Send first block
16:39:18:957 DataSocketPutDataSent 1725
16:39:18:958 04209650 TriggerDataSent 1256
16:39:18:958 DataSocketPutDataSent 0
16:39:18:958 04209650 TCustomWSocket.Shutdown 1 1256
16:39:19:010 >|226 Transfer complete|
16:39:19:010 ! Next3PutAsync
16:39:19:011 ! Data Session closed
16:39:19:011 ! Next3PutAsync
16:39:19:011 ! HighLevelAsync 0
16:39:19:011 ! HighLevelAsync done
16:39:19:011 04209650 TCustomWSocket.Shutdown 1 1256
16:39:19:849 Putting done
16:39:19:849 Renaming file
16:39:19:849 ! HighLevelAsync 0
16:39:19:849 04208E90 TriggerDataSent 1180
16:39:19:884 >|350 File or directory exists, ready for destination name|
16:39:19:884 ! HighLevelAsync 0
16:39:19:884 04208E90 TriggerDataSent 1180
16:39:19:919 >|250 Rename successful|
16:39:19:920 ! HighLevelAsync 0
16:39:19:920 ! HighLevelAsync done
16:39:20:849 Renaming done
16:39:20:849 ===Processing C:\Cumulus\web\weathercloud_realtime.txt
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing 0
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:849 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ===Processing
16:39:20:850 ========= End of realtime FTP ==========
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 12:34 pm
by steve
But my unanswered question is: Is it actually doing anything with those files at that point, or are you just making assumptions from something you are misinterpreting in a diagnostic file? From the timestamps, it would appear to be the latter.
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 12:46 pm
by BCJKiwi
I thought I had covered that here;
The CUtagsT.txttmp file time stamp is on the Tag processing time, not realtime so it may not actually be processed.
However all I can say is that that is the timestamp, I cannot say if any time is taken with the file but the log would appear to indicate there is virtually none;
16:39:14:654 ===End of upload of realtime.txt
16:39:14:654 ===Processing /httpdocs/weather/CUtags.php
16:39:14:655 ===Processing /httpdocs/wxshare/cloudbaseCU.txt
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 1:09 pm
by steve
Good, so it's working as expected and only generating and uploading realtime files at the realtime interval. Non-realtime files are not generated or uploaded at the realtime interval, and hence are not contributing in any significant way to the time taken to do the realtime uploads.
FTP is basically a very slow inefficient protocol. Sending the files one at a time doesn't help, perhaps in the future I could look at sending more than one file at a time.
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 1:19 pm
by mcrossley
Or add support for sending to a websocket?
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 1:29 pm
by steve
Yes, and also PHP file upload, I guess.
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 1:35 pm
by mcrossley
Yes, http file upload may get around some of the service provider restrictions on ftp as well. Assuming they would allow PHP file upload.
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 1:45 pm
by mcrossley
I also saw WD recently added the ability to send data using a
custom HTTP get command.
Re: Realtime.txt update behaviour
Posted: Tue 07 Apr 2015 1:50 pm
by steve
I very nearly added that last night as I was changing all of the other http code. It was just (as usual) the overhead of adding all of the configuration stuff that put me off. Coming soon, though, most likely; a few people have asked for this in the past.