24 hour timer

Hello

We are currently facing a weird issue that we can not explain.
We are using multiple boards which we program for offline use with an Android App.
This App creates a timer which fires every 24 hours.
Most of the times. this works as expected. But sometimes the cylce of the timer seems to change, meaning that, for example, when the 24 hour timer was firing every day at 6 o'clock, it changes and continues to fire at 8 o'clock instead.
Weirdly, it does not seem to happen consistently. The only clue that we found was that it seems to only happen when the switch was pressed in between two cycles.
The switch also starts another timer - so maybe this influences the 24hour timer?

Do you have any explanation what could cause this issue?
All boards are from type MetaMotion R and are running firmware 1.4.1

Thank you very much for your help!

Greetings from Vienna
Jodli

Comments

  • Can you post your code and replicable steps?

  • edited April 2019

    Post the relevant timer code you are running.

    • Does the issue consistently happen once you press the switch?
    • Do you see the same behavior with the switch and timer if your 24 hour timer uses a shorter period?
  • Ah sorry. I should have thought about the code by myself. Unfortunately the code is pretty long and complex. I tried to reduce it as much as possible, but I also wanted to leave in as much as possible so you can maybe spot something that I missed. I hope it is clear enough to read:

    Code for the switch:

    //Goal:
    //We want to log the number of clicks in a 3 seconds time period
    //we also want one dataset from the accelerator per click
    //Note: route is just a class that holds all configurations for the switch
    
    //create switch-buffers; switch_count is the buffer for the number of clicks; switch_state is the buffer for the log:
    switchModule.state().addRouteAsync((RouteComponent source) -> {
        source.filter(Comparison.EQ, 0).count().name("switch_count").buffer().name("switch_state");
    }).continueWithTask((Task<Route> switch_pre_task) -> {//create the logger
        if(switch_pre_task.isFaulted())
            throw switch_pre_task.getError();
    
        route.switch_pre_count_id = switch_pre_task.getResult().id();
    
        //start logging the switch-buffer:
        return dataprocessorModule.state("switch_state").addRouteAsync((RouteComponent source) -> {
            source.log(null);
        });
    }).continueWithTask((Task<Route> buffer_task) -> {//create the 3-seconds-timer
        if(buffer_task.isFaulted())
            throw buffer_task.getError();
    
        Route result = buffer_task.getResult();
        route.switch_pre_state_id = result.id();
        route.switch_identifier = result.generateIdentifier(0);
    
        //3-seconds-timer:
        return timerModule.scheduleAsync(3000, (short) 1, true, () -> {
            //Feedback
            vibrationModule.startMotor(50f, (short) 3000);
            ledModule.stop(true);
            ledModule.editPattern(Led.Color.valueOf("BLUE"), Led.PatternPreset.PULSE).highTime((short) 1000).pulseDuration((short) 2500).repeatCount((byte) 1).commit();
            ledModule.play();
    
            //log the number of clicks and reset the counter:
            dataprocessorModule.state("switch_state").read();
            dataprocessorModule.edit("switch_count", DataProcessor.CounterEditor.class).reset();
        });
    }).continueWithTask(timer_task -> { //configure accelerometer
        if(timer_task.isFaulted())
            throw timer_task.getError();
    
        route.timer_id = timer_task.getResult().id();
    
        accelerometerModule.configure()
                .odr(2f)    //we don't really care for delay
                .range(4f)
                .commit();
    
        return accelerometerModule.acceleration().addRouteAsync((RouteComponent source) -> {
            source.log(null);
            //we only want one single entry. So we automatically stop the accelerator right after we got one:
            source.react((DataToken token) -> {
                accelerometerModule.stop();
                accelerometerModule.acceleration().stop();
            });
        });
    
    }).continueWithTask((Task<Route> acc_task) -> {//react to button presses
        if(acc_task.isFaulted())
            throw acc_task.getError();
        else {
            Route result = acc_task.getResult();
            route.acc_id = result.id();
            route.acc_identifier = result.generateIdentifier(0);
    
            return switchModule.state().addRouteAsync((RouteComponent source) -> {
                source.filter(Comparison.EQ, 1).react((DataToken token) -> {
                    ledModule.stop(true);
                    ledModule.editPattern(Led.Color.valueOf("GREEN"), Led.PatternPreset.PULSE).highTime((short) 1000).pulseDuration((short) 2500).repeatCount((byte) 1).commit();
                    ledModule.play();
    
                    if(route.vibration)
                        vibrationModule.startMotor(route.vibration_strength, route.vibration_ms);
    
    
                    Timer.ScheduledTask timer = timerModule.lookupScheduledTask(((byte) route.timer_id));
                    if(timer != null) {
                        //The timer should run out 3 seconds after the LAST switch-press, so we restart the timer:
                        timer.stop();
    
                        timer.start();
                    }
    
                    //this will log the accelerometer:
                    accelerometerModule.start();
                    accelerometerModule.acceleration().start();
                });
            });
        }
    }).continueWith((Task<Route> switch_post_task) -> {
        if(switch_post_task.isFaulted()) {
            log(switch_post_task.getError());
            remove_switch_routes();
        }
        else {
            Route result = switch_post_task.getResult();
            if(result != null) {
                route.switch_post_id = result.id();
    
                logModule.start(false);
            }
    
            //uses board.serialize(ByteArrayOutputStream) and saves it into a sql-database:
            save_state();
        }
        return null;
    });
    

    Code for the timer:

    //Goal:
    //create a timer that buzzed every 24 hours.
    //To make sure that the 24-hour timer buzzes at a preconfigured time, a second timer "positions" the 24-hour timer.
    //After the 24 hour-timer is positioned the second timer is not needed anymore
    //Note: bing is just a class that holds all configurations for our timer
    timerModule.scheduleAsync(86400000, false, () -> {
        if(bing.led) {
            ledModule.stop(true);
            ledModule.editPattern(Led.Color.valueOf(bing.color), Led.PatternPreset.PULSE).highTime((short) 1000).pulseDuration((short) 2500).repeatCount((byte) 3).commit();
            ledModule.play();
        }
    
        if(bing.vibration)
            vibrationModule.startMotor(bing.vibration_strength, bing.vibration_ms);
    }).continueWithTask(loopTask -> {// wait timer which "positions" the 24h loop to the right time
        if(loopTask.isFaulted())
            throw loopTask.getError();
        else {
            final Timer.ScheduledTask scheduledTask_loop = loopTask.getResult();
            bing.id_loop = scheduledTask_loop.id();
    
            //
            //creating wait timer (can be removed after loop-timer has started)
            //bing.countdown is calculated by substracting getTimeInMillis() of the current time from getTimeInMillis() of the target time
            //
            return timerModule.scheduleAsync(bing.countdown, (short) 1, true, scheduledTask_loop::start);
        }
    }).continueWith(wait_Task -> { //concluding configurations
        if(wait_Task.isFaulted()) {
            log(R.string.error_timer_failed, wait_Task.getError());
            remove_bing(bing);
        }
        else {
            final Timer.ScheduledTask scheduledTask_wait = wait_Task.getResult();
            scheduledTask_wait.start();
    
            bing.id_wait = scheduledTask_wait.id();
            //uses board.serialize(ByteArrayOutputStream) and saves it into a sql-database:
            save_state();
        }
        return null;
    });
    

    It does not happen consistently which makes it so hard to pinpoint the issue. We have a feeling that it only happens on specific boards, but even there it does not happen consistently (it neither happens every time nor is the change similar).
    The weird thing is that almost every time the first cycle of the timer is correct (and in the few instances where it is not, it is only off by a few minutes). It is also not consistent WHEN the cycle changes. There were instances where the cycle of a timer was correct for several days and then changed. Other boards changed almost every day. The only consistency I can see is that when the cycle changed, the switch was pressed somewhere in between this cycle and the cycle before.
    But there were also instances where the switch was pressed without the cycle changing. So whatever effect the switch has on the timer, it is not consistent either
    Is it possible that we are facing some kind of hardware defect?

    I havent tried it with shorter periods yet. Could there be an issue with very long timer-cycles?

    Thank you very much for your help!
    Jodli

  • edited April 2019

    The code looks fine to me.

    There is also a lot going on in your code. To get to the bottom of this, it would be very helpful to:

    1. Have a minimum amount of code that reproduces the issue.
      • it would be ideal if the problem occurs with just timer and switch code.
    2. Rework the code such that it is entirely self contained within a function, ala:


    static void setup(final MetaWearBoard MetaWear) {
    }
    
  • Thank you very much for your reply. I did some further testing and it seems that the problem persists if I reduce the 24-hour timer to only 5 minutes and that the 3-seconds-timer from the switch seems to cause the problem.

    I logged the exact times when the board vibrated and had minor fluctuations in seconds (almost every time).

    When I just removed the lines from the switch-logic:
    timer.stop();
    timer.start();

    Then the seconds where absolutely exact.

    I will try to reduce the code as much as possible so you can replicate it easier

  • Ok I reduced my code as much as possible and tested a bit. There definitely is something fishy going on.

    My code creates a route to the battery to logs its output and then creates a loop-timer which just reads the battery state. I did this to have a way of logging the exact timings of my loop-timer.
    Then, a 3 second "dummy"-timer is created, which is started when pressing the switch.
    This is my code, you should be able to just use it as is, to replicate my issue:

    static void setup(final MetaWearBoard MetaWear) {
        Settings settingsModule = MetaWear.getModule(Settings.class);
        Timer timerModule = MetaWear.getModule(Timer.class);
        Haptic vibrationModule = MetaWear.getModule(Haptic.class);
        Switch switchModule = MetaWear.getModule(Switch.class);
        Logging logModule = MetaWear.getModule(Logging.class);
    
    
        settingsModule.battery().addRouteAsync(source -> {//create battery-logging
            source.log((data, env) -> {//we will use this to get the timestamps for the loop-timer
                Log.i("log", Long.toString(data.timestamp().getTimeInMillis()));
            });
        }).continueWithTask(task -> {//create loop timer
            return timerModule.scheduleAsync(10000, false, () -> {
                vibrationModule.startMotor(50, (short) 200);
                settingsModule.battery().read();
            });
        }).continueWithTask(loopTask -> {//create 3 seconds "dummy"-timer which is started by the switch
            loopTask.getResult().start(); //start loop-timer
    
            return timerModule.scheduleAsync(3000, (short) 1, true, () -> {
                //we only need this timer to exist. It does not have to do anything to cause problems
            });
        }).continueWithTask(dummyTask -> {//create switch logic
            final long test_timer_id = dummyTask.getResult().id();
    
            return switchModule.state().addRouteAsync((RouteComponent source) -> {
                source.filter(Comparison.EQ, 1).react((DataToken token) -> {
                    vibrationModule.startMotor(50, (short) 200);
    
                    Timer.ScheduledTask timer = timerModule.lookupScheduledTask(((byte) test_timer_id));
                    if(timer != null) {
                        timer.start();
                    }
                });
            });
        }).continueWith((Task<Route> switchTask) -> {
            logModule.start(false);
            vibrationModule.startMotor(50, (short) 100);
            return null;
        });
    }
    

    Code for downloading:

    static void download(final MetaWearBoard MetaWear) {
        MetaWear.getModule(Logging.class).downloadAsync().continueWith(task -> {
            Log.i("log", "Done");
            return null;
        });
    }
    

    In theory, the timestamps for the battery logging should be exactly 10 seconds apart. And in fact, when I just run my code, let the timer fire for a few times and then download the log data, there are only minor fluctuations in the timestamps (2 ms at max):

    I/log: 1555319227956
    I/log: 1555319237956
    I/log: 1555319247955
    I/log: 1555319257956
    I/log: 1555319267956
    I/log: 1555319277955
    I/log: 1555319287956

    But when I just press the button in between each loop, then all timestamps fluctuate up to 500 ms. And as far as I can see, that should be impossible because the switch is doing nothing that should interfere with the loop-timer:

    I/log: 1555319297956
    I/log: 1555319307509
    I/log: 1555319316973
    I/log: 1555319326842
    I/log: 1555319336766
    I/log: 1555319346700
    I/log: 1555319356651

    Another interesting find is that when I only remove the line "timer.start()" from the code - meaning that the "dummy"-timer is not started by the switch anymore - then all timestamps seem to be exact again.
    So I guess that starting a timer while another timer is running, for some reason interferes with the already running timer.

    Do you have an idea how I could overcome that problem?
    Am I overlooking something?
    A small difference in ms is not a big deal for us. But it seems that the longer the timer, the longer the possible fluctuations. This means, that a timer that fires every 24 hours can fluctuate over several hours :/

    Thank you for any tips or remarks
    Jodli

  • Thanks for the code snippet, which looks fine to me. We'll try to replicate the issue on our end with your code.

  • Thank you very much! I am looking forward to hear from your findings :)

  • @Jodli said:
    Thank you very much! I am looking forward to hear from your findings :)

    Confirmed the behavior with your code. I have forwarded the issue to the firmware dev.

  • Thank you. Good to know, that I was not going crazy :D

    Just so we can plan accordingly: Do you have an estimation when a fix can be expected?

    Thanks again!

  • edited May 2019

    Sorry to bump again, but I wanted to ask about the timeline for a possible firmware upgrade regarding the issue above. We have a large scientific project here on the start (using 180 wearables from mbientlab) and cannot start without having this issue solved.

  • I will check with the firmware Dev.

  • The timer fix is still a WIP. In the meantime, you can use the light sensor as a fake timer by sampling data at 1s intervals. Once you have 3 samples, you know 3 seconds has elapsed.

    final AmbientLightLtr329 als = MetaWear.getModule(AmbientLightLtr329.class);
    als.illuminance().addRouteAsync(
            source -> source.count().name("counter").filter(Comparison.EQ, 3).react(token -> {
                MetaWear.getModule(DataProcessor.class)
                .edit("counter", DataProcessor.CounterEditor.class)
                            .reset();
                led.stop(true);
                als.illuminance().stop();
            })
    
    switchModule.state().addRouteAsync((RouteComponent source) -> {
            source.filter(Comparison.EQ, 1).react((DataToken token) -> {
                led.editPattern(Led.Color.GREEN, Led.PatternPreset.SOLID)
                    .commit();
                led.play();
                als.illuminance().start();
            });
    });
    
  • Hmm thank you very much for that suggestion. Unfortunately we are already using most of the boards ressources and can not afford setting up any additional routes. Also, we need to conserve as much battery as possible. So I fear that setting up another route to an additionnal sensor will not do us any good :/

    But thanks. We will try to make due with the current situation and hope that your update will be out soon :)

  • Hello, I am sorry again.
    We realised that this firmwarebug causes a lot more problems for us than we initially anticipated.

    Has there been any progress?

    As an IT-guy I totally understand that developement can not and should not be rushed. So I get that "it is done when it is done". I just hope I can increase the priority on this issue a bit - if possible :)

    Thanks again for your support!

  • @Jodli said:
    Hello, I am sorry again.
    We realised that this firmwarebug causes a lot more problems for us than we initially anticipated.

    Has there been any progress?

    Yes, our firmware dev published a release candidate. Barring any unforeseen issues, it should be available for the public tomorrow.

  • Uh that sounds great. Thank you very much for the heads up!

Sign In or Register to comment.