locked Detected dropped audio source samples and Syslog #AudioIssues #logging


Richard Waterman
 

Hello,

I would be grateful if someone could answer a couple of questions for me:

Summary:
1. Am I right in believing that wsjtx_syslog.log started life when wsjt-x 2.3.0 was released?
2. Looking at the Syslog file, I see that I am getting frequent warnings "Detected dropped audio source samples".  What is the likely cause? Why do some warnings have a negative number?

Detail behind my questions:
I am running Windows 10 Pro, latest update on an i&-6700T processor with 16Gb RAM
Processor load rarely exceeds 20% loading (as seen using task manager) and is typically 4-5%
Running wsjt-x 2.3.1
Running latest JTAlert
Running Omnirig
Running Task Manager
Running TeamViewer
Other than that, just background Windows processes.

Warnings occur even with only a couple of stations received on an afternoon 80m band
Here is a short sample from earlier today:

[SYSLOG][2021-05-08 14:25:44.385395][64:53:48.030945][warning] Detected dropped audio source samples: -672 (-0.014 S)
[SYSLOG][2021-05-08 14:25:59.398520][64:54:03.043840][warning] Detected dropped audio source samples: 624 (0.013 S)
[SYSLOG][2021-05-08 14:27:59.400122][64:56:03.044920][warning] Detected dropped audio source samples: 576 (0.012 S)
[SYSLOG][2021-05-08 14:28:59.398204][64:57:03.042325][warning] Detected dropped audio source samples: 480 (0.01 S)
[SYSLOG][2021-05-08 14:32:44.400249][65:00:48.043285][warning] Detected dropped audio source samples: 576 (0.012 S)
[SYSLOG][2021-05-08 14:32:59.389673][65:01:03.032795][warning] Detected dropped audio source samples: -528 (-0.011 S)
[SYSLOG][2021-05-08 14:33:44.401526][65:01:48.044568][warning] Detected dropped audio source samples: 528 (0.011 S)
[SYSLOG][2021-05-08 14:37:44.390367][65:05:48.031884][warning] Detected dropped audio source samples: -480 (-0.01 S)
[SYSLOG][2021-05-08 14:45:29.392119][65:13:33.030680][warning] Detected dropped audio source samples: -480 (-0.01 S)

Radio is a KX3 interfaced via a ZLP Electronics USB Data interface with built in soundcard.
Radio left monitoring on receive 24/7.  No transmission, so there is no Rx/Tx switching

With regards to my syslog question, I occasionally look in the wsjt-x log directory (usually when I think ALL.txt might be getting a bit large) and this time noticed wsjtx_syslog.log.  Not seen that before.  Looking through release notes, I see a mention of additional logging in the notes for 2.3.0_rc2.  I installed 2.3.0 on 5th Feb 2021 and the earliest syslog file I have starts entries from 5th Feb.  There are three syslog files stored in the logs subdirectory of the log directory, dated 01 March 2021, 01 April 2021 and 01 May 2021.  The current syslog file is in the base log directory and is updated dynamically as warnings occur. Presumably, it will be saved to the logs directory on 01 June 2021.

Additional syslog questions: how many files will be kept before "rotation" occurs, as mentioned in the release notes and how do I configure what is logged?  I can't find anything in the user guide.

Would really appreciate any info.

73, Richard, G4KRW


Bill Somerville
 

On 08/05/2021 17:42, Richard Waterman wrote:
Hello,

I would be grateful if someone could answer a couple of questions for me:

Summary:
1. Am I right in believing that wsjtx_syslog.log started life when wsjt-x 2.3.0 was released?
2. Looking at the Syslog file, I see that I am getting frequent warnings "Detected dropped audio source samples".  What is the likely cause? Why do some warnings have a negative number?

Detail behind my questions:
I am running Windows 10 Pro, latest update on an i&-6700T processor with 16Gb RAM
Processor load rarely exceeds 20% loading (as seen using task manager) and is typically 4-5%
Running wsjt-x 2.3.1
Running latest JTAlert
Running Omnirig
Running Task Manager
Running TeamViewer
Other than that, just background Windows processes.

Warnings occur even with only a couple of stations received on an afternoon 80m band
Here is a short sample from earlier today:

[SYSLOG][2021-05-08 14:25:44.385395][64:53:48.030945][warning] Detected dropped audio source samples: -672 (-0.014 S)
[SYSLOG][2021-05-08 14:25:59.398520][64:54:03.043840][warning] Detected dropped audio source samples: 624 (0.013 S)
[SYSLOG][2021-05-08 14:27:59.400122][64:56:03.044920][warning] Detected dropped audio source samples: 576 (0.012 S)
[SYSLOG][2021-05-08 14:28:59.398204][64:57:03.042325][warning] Detected dropped audio source samples: 480 (0.01 S)
[SYSLOG][2021-05-08 14:32:44.400249][65:00:48.043285][warning] Detected dropped audio source samples: 576 (0.012 S)
[SYSLOG][2021-05-08 14:32:59.389673][65:01:03.032795][warning] Detected dropped audio source samples: -528 (-0.011 S)
[SYSLOG][2021-05-08 14:33:44.401526][65:01:48.044568][warning] Detected dropped audio source samples: 528 (0.011 S)
[SYSLOG][2021-05-08 14:37:44.390367][65:05:48.031884][warning] Detected dropped audio source samples: -480 (-0.01 S)
[SYSLOG][2021-05-08 14:45:29.392119][65:13:33.030680][warning] Detected dropped audio source samples: -480 (-0.01 S)

Radio is a KX3 interfaced via a ZLP Electronics USB Data interface with built in soundcard.
Radio left monitoring on receive 24/7.  No transmission, so there is no Rx/Tx switching

With regards to my syslog question, I occasionally look in the wsjt-x log directory (usually when I think ALL.txt might be getting a bit large) and this time noticed wsjtx_syslog.log.  Not seen that before.  Looking through release notes, I see a mention of additional logging in the notes for 2.3.0_rc2.  I installed 2.3.0 on 5th Feb 2021 and the earliest syslog file I have starts entries from 5th Feb.  There are three syslog files stored in the logs subdirectory of the log directory, dated 01 March 2021, 01 April 2021 and 01 May 2021.  The current syslog file is in the base log directory and is updated dynamically as warnings occur. Presumably, it will be saved to the logs directory on 01 June 2021.

Additional syslog questions: how many files will be kept before "rotation" occurs, as mentioned in the release notes and how do I configure what is logged?  I can't find anything in the user guide.

Would really appreciate any info.

73, Richard, G4KRW
Hi Richard,

small numbers like that can be ignored, we had to set the cut off somewhere. Negative numbers indicate more samples than expected. The counts are for each period of the current mode, there is never an exact expected count due to latencies between soundcard and software. In summary, you have nothing to worry about, if the discrepancies are of the order of 0.5 seconds and happen often then you would have a problem with your audio streaming throughput or system timekeeping.

Log files are rotated monthly or if they exceed a certain size, old rotated logs are deleted. IIRC 12 old logs are kept, the total amount of log data will be small. There are options to increase the logging verbosity using a configuration file, but for most users the default with no logging configuration file will be fine.

73
Bill
G4WJS.


Richard Waterman
 

That's great, many thanks Bill.

73, Richard, G4KRW