Page 1 of 2

Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 9:50 am
by broadstairs
I noticed that in November my data log has 2 records for the same minute but with different data in each! Is this normal? I should say that this started at 09:42 on 26th November. The December log is back to one record per minute! This is the same log which had a single number 9 as the second record for the 10:35 time as reported in my other thread! This double record continued until 10:36 on the 30/11/22 when it went back to a single record per minute at 10:36.

Stuart

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 2:12 pm
by mcrossley
I don't know how that could happen, unless two instances of CMX were running, but in your case they would be using the same config file and the same station.

What data is different and what is the same in the duplicated entries?

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 2:59 pm
by broadstairs
Mark

Below are just a sample but the first pair are not identical, many are but not all the lines at 10:40 are also different. The 9 line is the one which caused WXSimate to fail.
29/11/22,10:31,8.8,97,8.4,3,10,351,0.0,2.2,1019.6,439.0,19.9,62,2,8.3,8.8,1.0,207,0.02,535.78,7.4,204,0.6,20,0.0,2.2,8.3,8.8
29/11/22,10:31,8.8,97,8.4,3,10,350,0.0,2.2,1019.6,439.0,19.9,62,2,8.2,8.8,1.0,205,0.02,535.78,7.4,204,0.6,38,0.0,2.2,8.2,8.8
29/11/22,10:32,8.9,97,8.4,4,10,354,0.0,2.2,1019.7,439.0,19.9,62,3,8.3,8.9,1.0,185,0.02,535.78,7.4,205,0.6,346,0.0,2.2,8.3,8.9
29/11/22,10:32,8.9,97,8.4,4,10,355,0.0,2.2,1019.7,439.0,19.9,62,3,8.3,8.9,1.0,185,0.02,535.78,7.4,205,0.6,346,0.0,2.2,8.3,8.9
29/11/22,10:33,8.8,97,8.4,4,10,357,0.0,2.2,1019.5,439.0,19.9,62,3,8.0,8.8,1.0,190,0.02,535.78,7.2,206,0.6,338,0.0,2.2,8.0,8.8
29/11/22,10:33,8.8,97,8.4,4,10,358,0.0,2.2,1019.5,439.0,19.9,62,3,8.0,8.8,1.0,190,0.02,535.78,7.2,206,0.6,338,0.0,2.2,8.0,8.8
29/11/22,10:34,8.9,97,8.4,4,10,359,0.0,2.2,1019.5,439.0,19.9,62,4,8.0,8.9,0.0,180,0.02,535.78,7.3,206,0.6,19,0.0,2.2,8.0,8.9
29/11/22,10:34,8.9,97,8.4,4,10,358,0.0,2.2,1019.5,439.0,19.9,62,4,8.0,8.9,0.0,180,0.02,535.78,7.2,206,0.7,19,0.0,2.2,8.0,8.9
29/11/22,10:35,8.9,97,8.4,4,10,1,0.0,2.2,1019.6,439.0,20.0,62,5,8.0,8.9,0.0,172,0.02,535.78,7.2,207,0.7,2,0.0,2.2,8.0,8.9
9
29/11/22,10:36,8.9,97,8.4,4,10,1,0.0,2.2,1019.6,439.0,20.0,62,3,8.0,8.9,1.0,183,0.02,535.78,7.2,208,0.7,293,0.0,2.2,8.0,8.9
29/11/22,10:36,8.9,97,8.4,4,10,1,0.0,2.2,1019.6,439.0,20.0,62,3,8.0,8.9,1.0,183,0.02,535.78,7.2,208,0.7,293,0.0,2.2,8.0,8.9
29/11/22,10:37,9.0,97,8.5,4,10,360,0.0,2.2,1019.7,439.0,20.0,62,6,8.1,9.0,1.0,203,0.02,535.78,7.4,209,0.7,17,0.0,2.2,8.1,9.0
29/11/22,10:37,9.0,97,8.5,4,10,360,0.0,2.2,1019.7,439.0,20.0,62,6,8.1,9.0,1.0,203,0.02,535.78,7.3,209,0.7,17,0.0,2.2,8.1,9.0
29/11/22,10:38,8.9,97,8.4,4,10,1,0.0,2.2,1019.7,439.0,20.0,62,6,7.9,8.9,1.0,198,0.02,535.78,7.2,210,0.7,352,0.0,2.2,7.9,8.9
29/11/22,10:38,8.9,97,8.4,4,10,1,0.0,2.2,1019.7,439.0,20.0,62,6,7.9,8.9,1.0,198,0.02,535.78,7.2,210,0.7,352,0.0,2.2,7.9,8.9
29/11/22,10:39,8.9,97,8.4,5,13,4,0.0,2.2,1019.7,439.0,20.0,62,6,7.8,8.9,1.0,184,0.02,535.78,7.1,210,0.7,26,0.0,2.2,7.8,8.9
29/11/22,10:39,8.9,97,8.4,5,13,4,0.0,2.2,1019.7,439.0,20.0,62,6,7.8,8.9,1.0,184,0.02,535.78,7.1,210,0.7,26,0.0,2.2,7.8,8.9
29/11/22,10:40,8.8,97,8.4,5,13,5,0.0,2.2,1019.8,439.0,20.0,62,6,7.7,8.8,1.0,204,0.02,535.78,7.0,211,0.7,22,0.0,2.2,7.7,8.8
29/11/22,10:40,8.9,97,8.4,5,13,5,0.0,2.2,1019.8,439.0,20.0,62,6,7.8,8.9,1.0,207,0.02,535.78,7.1,211,0.8,37,0.0,2.2,7.8,8.9
29/11/22,10:41,8.9,97,8.4,5,13,6,0.0,2.2,1019.7,439.0,20.0,63,4,7.9,8.9,1.0,199,0.02,535.78,7.1,212,0.8,12,0.0,2.2,7.9,8.9
29/11/22,10:41,8.9,97,8.4,5,13,6,0.0,2.2,1019.7,439.0,20.0,63,4,7.9,8.9,1.0,199,0.02,535.78,7.1,212,0.8,12,0.0,2.2,7.9,8.9
29/11/22,10:42,8.9,97,8.4,4,13,6,0.0,2.2,1019.8,439.0,20.0,62,5,7.9,8.9,1.0,198,0.02,535.78,7.1,213,0.8,20,0.0,2.2,7.9,8.9
29/11/22,10:42,8.9,97,8.4,4,13,6,0.0,2.2,1019.8,439.0,20.0,62,5,7.9,8.9,1.0,198,0.02,535.78,7.1,213,0.8,20,0.0,2.2,7.9,8.9
Stuart

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 3:43 pm
by broadstairs
Mark I do not believe I had more than one CMX running because I always run it manually at present so I'd have to start two consoles to run it and I did not. I can't be sure whether or not this happened after a restart as I don't have the MXDiags any more for that time period.

Stuart

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 4:32 pm
by water01
Easy way to stop a second instance Program Settings > General Options > Stop second instance

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 4:41 pm
by broadstairs
I had that set when I originally setup CMX and it still is set.

Stuart

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 4:42 pm
by mcrossley
Do you still have the log file for when the duplicates were created?

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 5:02 pm
by broadstairs
I posted it on this thread. At least I think it's that one.

viewtopic.php?p=168022#p168022

Stuart

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 5:09 pm
by mcrossley
It is thanks.

That shows the routine that writes to the log file was only being called once, e.g...

Code: Select all

2022-11-29 10:31:00.290 DoLogFile: Writing log entry for 29/11/2022 10:31:00
2022-11-29 10:31:00.290 DoLogFile: max gust: 10
2022-11-29 10:31:00.290 DoLogFile: log entry for 29/11/2022 10:31:00 written
So, the duplicate entry at 10:31 (and the rest) must have come from another process.

Do you have the "Stop second instance" option enabled in Program settings/ General settings?

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 7:45 pm
by broadstairs
Yes I do have that set. Remember this is running under Linux/Mono.

Stuart

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 8:15 pm
by SamiS
Despite the setting of stopping another instance the symptoms very much seem like there would be two instances running.

@Mark: How foolproof is the detection if first instance is run as service (maybe under root permissions) and second instance from commandline as different user? And if I am correct, this would actually cause processes to keep their own differently named logfiles in MXdiags folder?

@Stuart: If that above is correct, you should have two logfiles on mxdiags covering the same time period. This could be seen also in file modified timestamps. Serviceconsolelog probably won’t show it because I think that the first running instance has it locked.


Sami

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 8:40 pm
by broadstairs
Let's be clear I do not run anything as a service, a second instance would have to be run manually and I did not do that. As for mxdiags I don't have any left from November.

Stuart

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 9:05 pm
by SamiS
broadstairs wrote: Wed 07 Dec 2022 8:40 pm Let's be clear I do not run anything as a service, a second instance would have to be run manually and I did not do that. As for mxdiags I don't have any left from November.
Mark made quite a strong statement above about how the logfile confirms, that the current CMX process wrote the data only once. So I’m just suggesting alternative scenarios that could explain the duplicates. Two running processes would also explain the minor differences between the duplicate lines, if the processes would both read the data from the station a few seconds apart and the values just change. But if you are sure that multiple instances can’t be the reason, then I’m definitely out of ideas.

Re: Data logs 2 records per minute?

Posted: Wed 07 Dec 2022 10:04 pm
by broadstairs
All I can say is that it only runs if I start a console and run it and there was only ever one console running. I do use ctrl+c to close it and it does take a long while to close occasionally and I have on occasion had to resort to force closing the console window before start a new console and start CMX again so unless Mono survives running CMX when I close the console (which it should not) then there cannot be two instances running. I do not run anything other than system processes as services and definitely NOT Mono/CMX.

Stuart

Re: Data logs 2 records per minute?

Posted: Thu 08 Dec 2022 10:36 am
by mcrossley
SamiS wrote: Wed 07 Dec 2022 8:15 pm @Mark: How foolproof is the detection if first instance is run as service (maybe under root permissions) and second instance from commandline as different user? And if I am correct, this would actually cause processes to keep their own differently named logfiles in MXdiags folder?
It creates a system mutex based on a static GUID allocated to CMX. It seems to be a pretty robust mechanism, killing a process can leave the system mutex open and you will get a warning on restarting (MX can detect the difference between an open and an abandoned mutex). How well it works with processes in different security contexts I'm not so sure, but as it is a system wide lock I'd expect it to work.