Bug: Volume changing after multiple overlapping announcements

[stamateviorel]

The problem is like this: If an announcement is already playing and another one comes without a volume value there is no sound. If an announcement is already playing and another one comes with a volume values there is no sound but when the last radio station playing comes back then the volume stays at the value of the second announcement.

This is super annoying because the volume jumps and then stays very loud especially if you were listening at a lower volume.

[linknum23]

This highlights a race condition in the save/restore handling for the announcement logic. The easiest fix would be to only save the state before the first overlapped announcement and only restore that state after the last overlapped announcement completes.

[linknum23]

A more advanced announcement interface would allow an overlapping announcement to either queue up (default) or interrupt the current announcement and start playing the new one.

The queue up implementation could use the current logic with a queue in front of it while the interrupting announcement would need to use the "only save first overlapped announcement" logic above.

[stamateviorel]

well right now i am busy on implementing a queue in openhab so i dont send to may request to the amplipi api. But indeed the amplipi should protect by itself from this. If you need any help let me know

[stamateviorel]

Ok after addind proposed changes in issue #508 i get a more nice experince in terms of volume. I still have to add my own implementation of queue in openhab but so far so good. For other interested:

const wordsPerMinute = 140;
const maxQueueSize = 200;
const percentageToRemove = 0.2; // 10%
let orderNumber = 0;
var logger = log('sayamplipi_logger');
let queue = [];
let processing = false;
let lastReceivedMessage = null;
let lastReceivedMessageTimestamp = null;
const triggerLimit = 5;
const triggerTimeWindow = 1000;
let triggerCount = 0;
let lastTriggerTime = 0;
const delayBeforeSpeaking = 5000; 

function isRateLimitExceeded() {
    const currentTime = Date.now();
    if (currentTime - lastTriggerTime > triggerTimeWindow) {
        lastTriggerTime = currentTime;
        triggerCount = 1;
        return false;
    }
    if (triggerCount >= triggerLimit) {
        return true;
    }
    triggerCount++;
    return false;
}

function processNextCommand() {
    try {
        if (!processing && queue.length > 0) {
            processing = true;
            const command = queue.shift();
            processMessage(command);
        } else {
            processing = false;
        }
    } catch (error) {
        logger.error(`Error in 'processNextCommand' function: ${error}`);
    }
}

function processMessage(command) {
    try {
    logger.info(`About to say message ${command.orderNumber}: ${command.message}`);

    let soundFile;
    if (command.message.startsWith('!important!')) {
        soundFile = "important.mp3";
        command.message = command.message.replace('!important!', '').trim();
        logger.info(`Message is important. Sound file set to ${soundFile}`);
    } else if (command.message.startsWith('!joke!')) {
        soundFile = "joke.mp3";
        command.message = command.message.replace('!joke!', '').trim();
        logger.info(`Message is a joke. Sound file set to ${soundFile}`);
    } else {
        soundFile = "call.mp3";
        logger.info(`Message is normal. Sound file set to ${soundFile}`);
    }

    if (soundFile) {
        actions.Audio.playSound(soundFile, 0.5);
        logger.info(`Playing sound file ${soundFile}`);
    }

    setTimeout(() => {
        const startTime = time.ZonedDateTime.now().toString();
        logger.info(`Start saying message ${command.orderNumber} at ${startTime}`);
        actions.Voice.say(command.message, 0.5);

        // Set a timeout for the next command
        setTimeout(() => {
            logger.info(`End saying message ${command.orderNumber} at ${time.ZonedDateTime.now().toString()}`);
            processing = false;
            processNextCommand();
            logger.info('Processed next command');
        }, command.durationMilliseconds);
    }, delayBeforeSpeaking);
} catch (error) {
    logger.error(`Error in 'processMessage' function: ${error}`);
}
}

rules.JSRule({
    name: "Listen to sayamplipi",
    description: "Listens for changes to the 'sayamplipi' item and queues them for processing",
    triggers: [
        triggers.ItemStateUpdateTrigger('sayamplipi')
    ],
    execute: () => {
        try {
            if (isRateLimitExceeded()) {
                logger.warn('Rate limit exceeded, ignoring trigger');
                return;
            }

            const newValue = items.getItem('sayamplipi').state;
            logger.info(`New value received: ${newValue}`);
            if (!newValue) {
                logger.info('sayamplipi changed to null or empty, ignoring');
                return;
            }

            const currentTime = time.ZonedDateTime.now().toInstant().toEpochMilli();

            if (newValue === lastReceivedMessage && currentTime - lastReceivedMessageTimestamp < 30000) {
                logger.info('sayamplipi changed to the same value within 30 seconds, ignoring');
                return;
            }

            const wordCount = newValue.split(' ').length;
            const bufferTimeMilliseconds = 5000;
            const durationMilliseconds = Math.round((wordCount / wordsPerMinute) * 60 * 1000 + bufferTimeMilliseconds);
            logger.info(`Estimated duration of message: ${durationMilliseconds} ms`);

            if (queue.length >= maxQueueSize) {
                const numToRemove = Math.floor(maxQueueSize * percentageToRemove);
                for (let i = 0; i < numToRemove; i++) {
                    queue.shift();
                }
            }
            const command = {
                orderNumber: ++orderNumber,
                message: newValue,
                durationMilliseconds: durationMilliseconds
            };
            queue.push(command);
            logger.info(`Added command to queue: ${JSON.stringify(command)}`);

            lastReceivedMessage = newValue;
            lastReceivedMessageTimestamp = currentTime;
            logger.info(`Updated last received message to: ${newValue}`);
            logger.info(`Updated last received message timestamp to: ${currentTime}`);

            if (!processing) {
                processNextCommand();
            }
        } catch (error) {
            logger.error(`Error in 'Listen to sayamplipi' rule: ${error}`);
        }
    }
});

[linknum23]

The main issue in fixing this is that announcements really need to be handled asynchronously to be able to fix this in a reliable way (see #421). This would require a bit of a redesign of the interface which is not on our current plans for the next couple of months.