Update Python target APIs to match the C target updates #1116

housengw · 2022-04-26T05:36:06Z

This PR updates the API of the python target according to the API change in the C target merged in #1097.

All of the old names are marked as deprecated.
Format:

old name -> new name means that the API is renamed from old name to new name. old name is still available in the current release, but will be removed in a future release.
old name (deprecated) means that the old name has not been renamed, and will be removed in a future release.
new name (new) means that the API is introduced in the linked PR.

Python target:
- get_current_tag -> lf.tag()
- compare_tags -> lf.tag_compare()
- get_microstep (deprecated)
- get_elapsed_logical_time -> lf.time.logical_elapsed()
- get_logical_time -> lf.time.logical()
- get_physical_time -> lf.time.physical()
- get_elapsed_physical_time -> lf.time.physical_elapsed()
- get_start_time -> lf.time.start()

lhstrh · 2022-04-28T00:09:01Z

Looks great!

Soroosh129

LGTM!

Arka2009 · 2022-05-03T14:26:13Z

How do I use lf.time.physical_elapse() now? When I try to schedule an action based on the physical elapsed time, I get the following error.

AttributeError: type object 'LinguaFranca.TimeType' has no attribute 'physical_elapse'`

I generated the python code using lfc (release 0.2.0) command line. Thereafter, I python3 -m pip install . in the generated directory and finally run python <Generated>.py

Am I missing something? Furthermore, the generated python code worked with the previous release of lfc.

edwardalee · 2022-05-03T14:58:22Z

Shouldn't it be lf.time.physical_elapsed()?

Arka2009 · 2022-05-03T15:46:29Z

Oops, my bad. Thanks for pointing out the typo.

Unfortunately, my code still does not work with latest release. The code fragment gets blocked at actionReadDisparityMap.schedule(0,(lf.time.physical_elapsed(),disparityMap)) , where actionReadDisparityMap is declared as a physical action.

if disparityMap is not None : 
      print(f"Trying to capture disparity {frameCnt}") 
      actionReadDisparityMap.schedule(0,(lf.time.physical_elapsed(),disparityMap)) 
      print(f"Captured disparity {frameCnt}") 
      frameCnt += 1

housengw · 2022-05-03T17:07:11Z

Would you mind elaborating on what you mean by "the code fragment gets blocked"? Does the line print(f"Captured disparity {frameCnt}") never gets printed?

Soroosh129 · 2022-05-03T17:38:14Z

I agree with @housengw that we need a bit more information about your specific situation to be able to comment definitively. Your program’s output would be really helpful. A fully executable minimal LF program that exhibits this behavior would be even better.

Based on the information that we have, is disparityMap a port? In that case, you would want to check and use disparityMap.value.

Arka2009 · 2022-05-04T06:06:30Z

I was able to recreate the problem, using a much simpler LF program below.

Source Code

    target Python;
    
    preamble {=
        import sys
        import pprint as pp
        import numpy as np
        import threading
        import time
    
        getLocalTime = lambda : time.strftime("%d %b %Y %H:%M:%S",time.localtime())
    
    =}
    
    reactor StereoCam {
        output rgbFrame
        output disparityMap
        state captureThread
        state captureThreadEnable
        physical action actionReadDisparityMap
        preamble {=         
            def luxonisThread(self,
                              actionReadDisparityMap):
                """
                    Continuouslty collect rgbFrames and disparity frames
                    from the webcam.
                """
                frameCnt = 0
                if self.captureThreadEnable.is_set():
                    while True:
                        print(f"{getLocalTime()}@Trying to capture disparity {frameCnt}")
                        actionReadDisparityMap.schedule(0,(lf.time.physical_elapsed(),frameCnt))
                        print(f"{getLocalTime()}@Captured disparity {frameCnt}")
                        frameCnt += 1
                        time.sleep(5)
        =}  
        
        reaction(startup) -> actionReadDisparityMap {=
            self.captureThreadEnable = threading.Event()
            self.captureThreadEnable.set()
            self.captureThread = threading.Thread(
                target = self.luxonisThread,
                args = (actionReadDisparityMap,)
            )
            self.captureThread.start()
        =}
    
        reaction(actionReadDisparityMap) -> disparityMap {=
            elapsedTime, disparityMapData = actionReadDisparityMap.value
            disparityMap.set(disparityMapData)
        =}
    
        reaction(shutdown) {=
            self.captureThreadEnable.clear()
            self.captureThread.join()
        =}
    }
    
    reactor plotter {
        input rgbFrame
        input disparityMap
        
        reaction(disparityMap) {=
            print(f"{getLocalTime()}@frame captured:{disparityMap.value}")
        =}
    
    }
    
    main reactor {
        plttr = new plotter()
        strcam = new StereoCam()
        strcam.rgbFrame -> plttr.rgbFrame
        strcam.disparityMap -> plttr.disparityMap
    }

The StereoCam reactor defines a function luxonisThread in the preamble, that schedules a actionReadDisparityMap inside a while True loop. After invoking schedule in every iteration it sleeps for 5s.

The StereoCam reactor defines three reactions, the startup reaction, that creates a thread and passes the luxonisThread as it thread function. It also sets the necessary flags (captureThreadEnable state) to trigger the while loop in the luxonisThread function. The actionReadDisparityMap reaction when triggered extracts the counter value that is set during each iteration of luxonisThread. The extracted value is then pushed via the output port disparityMap. The shutdown if for cleanup functions.

The plotter reactor takes the disparityMap from StereoCam reactor and prints its value.

The get the following problem after running the python code.

Basically the print(f"{getLocalTime()}@Captured disparity {frameCnt}") never executes. So I am guessing that it is stuck in actionReadDisparityMap.schedule(0,(lf.time.physical_elapsed(),frameCnt)).

I am running the generated python code in Raspberry-Pi4 (Linux pios3 5.15.32-v7l+ #1538 SMP Thu Mar 31 19:39:41 BST 2022 armv7l GNU/Linux). The lfc compiler is also invoked from the same host.

housengw · 2022-05-04T07:03:56Z

I used the exact code you provided but was unable to reproduce the halting behavior. Are you using the latest version of lfc? You can double check by rebuilding lfc using the command build-lfc. If that doesn't solve the problem, try build-lfc --clean.

Below is the output of my program:

wonghouseng@wessel:~/lingua-franca/test/Python$ python3 /home/wonghouseng/lingua-franca/test/Python/src-gen/TT/TT.py
---- Start execution at time Wed May  4 00:02:10 2022
---- plus 936527382 nanoseconds.
---- Using 24 workers.
04 May 2022 00:02:10@Trying to capture disparity 0
04 May 2022 00:02:10@Captured disparity 0
04 May 2022 00:02:10@frame captured:0
04 May 2022 00:02:15@Trying to capture disparity 1
04 May 2022 00:02:15@Captured disparity 1
04 May 2022 00:02:15@frame captured:1
04 May 2022 00:02:20@Trying to capture disparity 2
04 May 2022 00:02:20@Captured disparity 2
04 May 2022 00:02:20@frame captured:2
^C---- Elapsed logical time (in nsec): 10,011,268,006
---- Elapsed physical time (in nsec): 12,959,542,335

Arka2009 · 2022-05-04T23:07:45Z

Right I was able to getting it working on a x86-64 Linux. However the problem seems to occur only on ARMv7 Linux (Raspberry Pi4). Furthermore, I noticed that the following lines of output in your run (also reproduced on x86-64 Linux)

---- Start execution at time Wed May  4 00:02:10 2022
---- plus 936527382 nanoseconds.
---- Using 24 workers.

Notice the Start execution at time Wed May 4 00:02:10 2022 is different from the output from Raspberry-Pi4 (Start execution at time Thu Jan 1 07:30:00 1970) as shown below.

---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 0 nanoseconds.
---- Using 4 workers.

Could be that the timer is not properly initialized in ARM platforms?

lhstrh · 2022-05-05T01:05:19Z

An implementation of the timing routines is chosen based on the platform on which the program is compiled. Could it be that the wrong implementation is being used? See: https://github.com/lf-lang/reactor-c/blob/2ceec60bc3d9b3420553f66813c40790d1e28c85/core/platform.h#L45

edwardalee · 2022-05-05T01:17:58Z

Very interesting. Is it possible that the Raspberry Pi has been running for 7 hours? In that case, it's clock is not synchronized to UTC. I have no idea, however, why this would cause schedule or time.physical_elapsed to not return...

We should drill into this. I suspect the ARMv7 is a 32 bit processor and maybe needs a different implementation of the time functions. I don't think we've done any testing on 32 bit processors running Linux (though we have done some testing on bare iron 32 bit processors).

Soroosh129 · 2022-05-05T02:02:37Z

Would you please enable logging and post the output here?

target Python {
    logging: DEBUG
}

Arka2009 · 2022-05-05T02:16:39Z

@lhstrh should I rebuild LFC for Raspberry-Pi4 from the source? I am using the release version (), which I suspect has been compiled for x86-64 Linux systems only.

@edwardalee here's the complete log from Raspberry-Pi's run

(.wasteboardpi4env) amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $ python SimplifiedPhysicalActions/SimplifiedPhysicalActions.py 
---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 0 nanoseconds.
---- Using 4 workers.
04 May 2022 08:48:55@Trying to capture disparity 0
04 May 2022 16:21:59@Captured disparity 0
04 May 2022 16:21:59@frame captured:0
04 May 2022 16:22:04@Trying to capture disparity 1
04 May 2022 16:26:51@Captured disparity 1
04 May 2022 16:26:51@frame captured:1
04 May 2022 16:26:56@Trying to capture disparity 2
04 May 2022 16:36:17@Captured disparity 2
04 May 2022 16:36:17@frame captured:2
04 May 2022 16:36:22@Trying to capture disparity 3
04 May 2022 16:57:04@Captured disparity 3
04 May 2022 16:57:04@frame captured:3
04 May 2022 16:57:09@Trying to capture disparity 4
04 May 2022 17:40:47@Captured disparity 4
04 May 2022 17:40:47@frame captured:4
04 May 2022 17:40:52@Trying to capture disparity 5
04 May 2022 17:55:46@Captured disparity 5
04 May 2022 17:55:46@frame captured:5
04 May 2022 17:55:51@Trying to capture disparity 6
04 May 2022 19:26:43@Captured disparity 6
04 May 2022 19:26:43@frame captured:6
04 May 2022 19:26:48@Trying to capture disparity 7
05 May 2022 06:36:37@Captured disparity 7
05 May 2022 06:36:37@frame captured:7
05 May 2022 06:36:42@Trying to capture disparity 8
^CWARNING: Memory allocated for tokens has not been freed!
WARNING: Number of unfreed tokens: 1.
---- Elapsed logical time (in nsec): 2,058,295,182

I actually kept the program running for around 24 hours on Raspberry Pi. And unbeknownst to me, it did execute some of the reactions, albeit with unreasonably long (and unpredictable) delays.

Arka2009 · 2022-05-05T02:18:10Z

@edwardalee and @Soroosh129. I do not have access to the board as of now. I would update the detailed spec and the new run result with debugging enabled soon.

lhstrh · 2022-05-05T02:55:36Z

@Arka2009, there is no need to rebuild lfc. I was referring to the compilation of Lingua Franca code, not the compilation of the Lingua Franca Compiler :-) I agree with @Soroosh129 that a run with DEBUG information would be useful. Other output that would be great to have:

cat /proc/cpuinfo
uname -r
date
cat /etc/*-release

Thanks!

Arka2009 · 2022-05-05T05:37:42Z

The DEBUG log is quite big (>300MB) for only seconds of program run. I am sharing it as a Dropbox Link (https://www.dropbox.com/s/mvjewtt79vdu1lb/SimplifiedPhysicalActionsDebugOut.txt?dl=0). Let me know if you can access it.

Besides the system information is below.

cat /proc/cpuinfo :


    processor       : 0
    model name      : ARMv7 Processor rev 3 (v7l)
    BogoMIPS        : 108.00
    Features        : half thumb fastmult vfp edsp neon vfpv3 tls vfpv4 idiva idivt vfpd32 lpae evtstrm crc32
    CPU implementer : 0x41
    CPU architecture: 7
    CPU variant     : 0x0
    CPU part        : 0xd08
    CPU revision    : 3

    processor       : 1
    model name      : ARMv7 Processor rev 3 (v7l)
    BogoMIPS        : 108.00
    Features        : half thumb fastmult vfp edsp neon vfpv3 tls vfpv4 idiva idivt vfpd32 lpae evtstrm crc32
    CPU implementer : 0x41
    CPU architecture: 7
    CPU variant     : 0x0
    CPU part        : 0xd08
    CPU revision    : 3

    processor       : 2
    model name      : ARMv7 Processor rev 3 (v7l)
    BogoMIPS        : 108.00
    Features        : half thumb fastmult vfp edsp neon vfpv3 tls vfpv4 idiva idivt vfpd32 lpae evtstrm crc32
    CPU implementer : 0x41
    CPU architecture: 7
    CPU variant     : 0x0
    CPU part        : 0xd08
    CPU revision    : 3

    processor       : 3
    model name      : ARMv7 Processor rev 3 (v7l)
    BogoMIPS        : 108.00
    Features        : half thumb fastmult vfp edsp neon vfpv3 tls vfpv4 idiva idivt vfpd32 lpae evtstrm crc32
    CPU implementer : 0x41
    CPU architecture: 7
    CPU variant     : 0x0
    CPU part        : 0xd08
    CPU revision    : 3

    Hardware        : BCM2711
    Revision        : b03115
    Serial          : 10000000e3930cb1
    Model           : Raspberry Pi 4 Model B Rev 1.5

uname -r : 5.15.32-v7l+
date: Thu 05 May 2022 01:15:40 PM +08

cat /etc/*-release:

    PRETTY_NAME="Raspbian GNU/Linux 11 (bullseye)"
    NAME="Raspbian GNU/Linux"
    VERSION_ID="11"
    VERSION="11 (bullseye)"
    VERSION_CODENAME=bullseye
    ID=raspbian
    ID_LIKE=debian
    HOME_URL="http://www.raspbian.org/"
    SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
    BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs

edwardalee · 2022-05-05T06:07:00Z

The long delays suggest that the time reported by Linux is not nanoseconds but is being interpreted as nanoseconds. In the trace you provided, it covered about 2 seconds of logical time in about 24 hours, which suggests that each bit of its time represents about 50 microseconds rather than one nanosecond.

This would explain the difference in starting dates reported on the two platforms. Using this website: https://www.unixtimestamp.com, the two dates have a ration roughly on the order of 50,000.

What time zone are you in? Knowing that, we could calculate the ratio exactly.

The following website suggests a C program you could compile and run to determine whether the clock resolution is 1 ns:

https://raspberrypi.stackexchange.com/questions/36674/raspberry-pi-raspbian-tick-rate-in-hz

As a wild guess, you could try this in the LF program:

target C {
flags: "--std=gnu99"
}

Soroosh129 · 2022-05-05T07:38:19Z

target C {
flags: "--std=gnu99"
}

We do ask CMake to require C11 but this is not the case for the Python target (which doesn’t use CMake). If the C standard is the problem, I can find a way to enforce C11 or C99 in the Python target as well.

One way to find that out is to create an equivalent (or a simpler test) program in the C target on the Raspberry Pi and see how it behaves.

Arka2009 · 2022-05-05T23:05:37Z

@edwardalee, my time zone is UTC+8:00 (Singapore Time).

@Soroosh129 based on your suggestion, I am trying to create an equivalent LF-C program as below

target C {
    threads: 4
};

preamble {=
    #include <time.h>
    #include <stdio.h>
    #include <stdlib.h>
    #include <unistd.h>
    #include <pthread.h>

    #define SLEEPINTRVL 1.34
    #define TIMEBUFFLEN 100
=}

reactor StereoCam {
    physical action actionReadDisparityMap: unsigned;
    state generator_thr: pthread_t;
    output frame_cnt_out: unsigned;
    preamble {=         
       void *thread_write_fn(void *targs) {
            unsigned frame_cnt = 0;
            char buff[TIMEBUFFLEN];
            // thread_data_t* tdata = (thread_data_t*)targs;
            while(1) {                
                time_t now = time(0);
                strftime(buff,TIMEBUFFLEN,"%Y-%m-%d %H:%M:%S.000",localtime(&now));
                printf("%s\t%d@thread_write_fn invoked",buff,frame_cnt);
                lf_schedule(actionReadDisparityMap,frame_cnt++);
                sleep(SLEEPINTRVL);
            }
        }
    =}  
    
    reaction(startup) {=
        /* Start the counter thread */
        int ret = pthread_create(&(self->generator_thr),NULL,thread_write_fn,NULL);
        if (ret == 0)
            printf("Thread succesfully created\n");
    =}

    reaction(actionReadDisparityMap) -> frame_cnt_out {=
        /* Read the counter thread and push the value to output port */
        lf_set(frame_cnt_out,actionReadDisparityMap->value);
    =}

    reaction(shutdown) {=
        pthread_join(self->generator_thr,NULL);
    =}
}

reactor plotter {
    input frame_cnt_out: unsigned;
    
    reaction(frame_cnt_out) {=
        char buff[TIMEBUFFLEN];
        time_t now = time(0);
        strftime(buff,TIMEBUFFLEN,"%Y-%m-%d %H:%M:%S.000",localtime(&now));
        printf("%s\t%d@plotter's only reaction invoked",buff,frame_cnt_out);
    =}

}

main reactor {
    plttr = new plotter()
    strcam = new StereoCam()
    strcam.frame_cnt_out -> plttr.frame_cnt_out
}

Here the thread_write_fn is passed as a thread function, that is created during the startup reaction of the StereoCam reactor. This function is responsible for scheduling the actionReadDisparityMap physical action inside its while loop after sleeping for SLEEPINTRVL in each iteration. However, I don't know how to pass a "reference" to actionReadDisparityMap. Is it okay to pass it via void *targs? In that case, I would need to typecast back into a suitable type, right? Is the type of actionReadDisparityMap still unsigned?

Once this code is ready, I can test it on Raspberry-Pi and amd64 desktop and study the behaviour with different compile options.

Soroosh129 · 2022-05-06T04:28:41Z

Thank you for taking the time to convert your code to C.

To answer your question, yes, you can pass the action as a void*, but you don't need to cast it when you call schedule(). AsyncCallBack.lf is a test program that does this.

edwardalee · 2022-05-06T06:40:36Z

Notice that you should use lf_schedule_int not lf_schedule. The second argument is a time delay, not a message payload. The documentation of these functions is here.

I suspect the problem with the implementation on the Raspberry Pi is more fundamental and would show up with a much simpler example. I suspect that the OS time functions we are relying on may not actually be POSIX compliant. Can you try running some of the tests? E.g., this one: ActionDelay. It should print:

SUCCESS. Elapsed logical time is 100 msec.

Arka2009 · 2022-05-06T13:35:58Z

Thanks for referring the Lingua-Franca handbook.

@edwardalee I was able to reproduce the anomalous behaviour with the test case. I had to run the generated binary with time command because of the misleading SUCCESS message that always gets printed regardless of the behaviour. For each of platforms, I performs 5 runs. For the Rapberry-Pi the time reports a measurement of 109-643ms, while for the x86-64/Linux the time reported a measurement of 103-104ms. The display log is below.

Raspberry-Pi4 (Raspbian OS, Bulls eye)

amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $ time /home/amaity/Desktop/WasteBoard_EdgePipeline/OUT/bin/SimplifiedC_2
---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 0 nanoseconds.
---- Using 4 workers.
Logical, physical, and elapsed logical: 100000000 100003696 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000

real    0m0.395s
user    0m0.133s
sys     0m0.234s
amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $ time /home/amaity/Desktop/WasteBoard_EdgePipeline/OUT/bin/SimplifiedC_2
---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 0 nanoseconds.
---- Using 4 workers.
Logical, physical, and elapsed logical: 100000000 99999571 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000

real    0m1.311s
user    0m0.559s
sys     0m0.726s
amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $ time /home/amaity/Desktop/WasteBoard_EdgePipeline/OUT/bin/SimplifiedC_2
---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 0 nanoseconds.
---- Using 4 workers.
Logical, physical, and elapsed logical: 100000000 100006075 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000

real    0m0.530s
user    0m0.123s
sys     0m0.381s
amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $ time /home/amaity/Desktop/WasteBoard_EdgePipeline/OUT/bin/SimplifiedC_2
---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 681845628 nanoseconds.
---- Using 4 workers.
Logical, physical, and elapsed logical: 781845628 781847564 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000
---- Elapsed physical time (in nsec): 100,345,189

real    0m0.109s
user    0m0.044s
sys     0m0.057s
amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $ time /home/amaity/Desktop/WasteBoard_EdgePipeline/OUT/bin/SimplifiedC_2
---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 0 nanoseconds.
---- Using 4 workers.
Logical, physical, and elapsed logical: 100000000 99996584 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000

real    0m0.643s
user    0m0.191s
sys     0m0.426s
amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $

x86-64 Linux

amaity@msi-500:~/Desktop/wasteboard_swintegration$ time /home/amaity/Desktop/wasteboard_swintegration/OUT/bin/SimplifiedC_2
---- Start execution at time Fri May  6 21:20:42 2022
---- plus 151779009 nanoseconds.
---- Using 8 workers.
Logical, physical, and elapsed logical: 1651843242251779009 1651843242251973435 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000
---- Elapsed physical time (in nsec): 100,693,395

real    0m0.103s
user    0m0.002s
sys     0m0.004s
amaity@msi-500:~/Desktop/wasteboard_swintegration$ time /home/amaity/Desktop/wasteboard_swintegration/OUT/bin/SimplifiedC_2
---- Start execution at time Fri May  6 21:20:43 2022
---- plus 296045302 nanoseconds.
---- Using 8 workers.
Logical, physical, and elapsed logical: 1651843243396045302 1651843243396246884 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000
---- Elapsed physical time (in nsec): 100,796,374

real    0m0.103s
user    0m0.000s
sys     0m0.005s
amaity@msi-500:~/Desktop/wasteboard_swintegration$ time /home/amaity/Desktop/wasteboard_swintegration/OUT/bin/SimplifiedC_2
---- Start execution at time Fri May  6 21:20:44 2022
---- plus 414773859 nanoseconds.
---- Using 8 workers.
Logical, physical, and elapsed logical: 1651843244514773859 1651843244514973683 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000
---- Elapsed physical time (in nsec): 100,800,786

real    0m0.104s
user    0m0.006s
sys     0m0.000s
amaity@msi-500:~/Desktop/wasteboard_swintegration$ time /home/amaity/Desktop/wasteboard_swintegration/OUT/bin/SimplifiedC_2
---- Start execution at time Fri May  6 21:20:45 2022
---- plus 447116322 nanoseconds.
---- Using 8 workers.
Logical, physical, and elapsed logical: 1651843245547116322 1651843245547321545 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000
---- Elapsed physical time (in nsec): 100,833,140

real    0m0.103s
user    0m0.001s
sys     0m0.004s
amaity@msi-500:~/Desktop/wasteboard_swintegration$ time /home/amaity/Desktop/wasteboard_swintegration/OUT/bin/SimplifiedC_2
---- Start execution at time Fri May  6 21:20:46 2022
---- plus 460051195 nanoseconds.
---- Using 8 workers.
Logical, physical, and elapsed logical: 1651843246560051195 1651843246560249971 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000
---- Elapsed physical time (in nsec): 100,847,716

real    0m0.104s
user    0m0.001s
sys     0m0.005s

FYI I ran the binary many more times on Raspberry Pi. There were quite often a perceptible delay (> 1.5s), which should ideally take around 0.1ms (as it does in x86-64/Linux platform). The binary runtime also varied a lot.

Soroosh129 · 2022-05-06T13:59:58Z

Just out of curiosity, how does the Python version of ActionDelay perform on the Pi?

Arka2009 · 2022-05-06T14:56:40Z

For the Python implementation of , the performance of generated code in Python is slightly "better" in the sense, the execution time time is 0.25-0.35s (less variation, albeit significantly higher that the ideal case of 0.1s).

On x86-64 running the Python generated code under time results around 0.11-0.13s of measured real elapsed time.

edwardalee · 2022-05-06T23:36:12Z

I don't see the display log, so I'm not sure what you mean by being able to reproduce the anomalous behavior. What exactly was the anomalous behavior?

Arka2009 · 2022-05-06T23:46:19Z

I mean the program output, including the output of time command. You can view it by clicking on triangle icon next to Raspberry Pi, it will unfold the section.

Arka2009 · 2022-05-06T23:54:04Z

I was expecting the compiled binary to run in little more than 0.1s (say 0.11-0.15s). Please correct if I am wrong. I use the time command to profile the execution time.

In x86-64/Linux platforms I observe this expected behaviour, not in Raspberry Pi.

edwardalee · 2022-05-07T00:05:26Z

Ok, I see it now...
I think this reinforces the idea of a mismatch in the time representation.
If you run 'date' on the R.Pi, do you see today's date?
If so, this is the right diagnosis, but I don't know to fix it.
It would seem that the R.Pi's implementation of the time functions is not POSIX compliant, in that case.

Soroosh129 · 2022-05-07T01:22:20Z

I think I still don’t see the anomalous behavior that was causing 2 seconds in logical time to take a day.

What I see from running ActionDelay is that the Raspberry Pi is slow, as expected:

amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $ time /home/amaity/Desktop/WasteBoard_EdgePipeline/OUT/bin/SimplifiedC_2
---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 0 nanoseconds.
---- Using 4 workers.
Logical, physical, and elapsed logical: 100000000 100003696 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000

real    0m0.395s
user    0m0.133s
sys     0m0.234s

Here, user time is shown as 133 msecs for 100 msec in logical time. Even if we take the highest number in the range, which would be 600 msecs, that can’t be due to time being reported as microseconds, I think, since 100 million microseconds is 1 minute 40 seconds.

Arka2009 · 2022-05-07T02:05:26Z

@Soroosh129 , there is also a case, where the user time is 559ms.

amaity@pios3:~/Desktop/WasteBoard_EdgePipeline $ time /home/amaity/Desktop/WasteBoard_EdgePipeline/OUT/bin/SimplifiedC_2
---- Start execution at time Thu Jan  1 07:30:00 1970
---- plus 0 nanoseconds.
---- Using 4 workers.
Logical, physical, and elapsed logical: 100000000 99999571 100000000.
SUCCESS. Elapsed logical time is 100 msec.
---- Elapsed logical time (in nsec): 100,000,000

real    0m1.311s
user    0m0.559s
sys     0m0.726s

Arka2009 · 2022-05-07T12:21:33Z

For now, I managed to get code working on Raspberry-Pi4 with Ubuntu-21.10. This serves my purpose for now.

Soroosh129 · 2022-05-09T15:14:46Z

@Arka2009 Would you please create an issue so that we don’t lose track of this?

housengw added 2 commits April 25, 2022 22:14

update python target api to match the c target updates

5ed0236

readd get_current_tag and deprecate it

101b3e0

housengw changed the base branch from master to set-destructor-variant April 26, 2022 05:36

housengw requested a review from Soroosh129 April 26, 2022 16:47

housengw self-assigned this Apr 26, 2022

housengw added the python Related to the Python target label Apr 26, 2022

housengw marked this pull request as draft April 26, 2022 17:11

housengw added 4 commits April 27, 2022 11:31

update pointer to submodule

7459ce6

Merge branch 'set-destructor-variant' into python-target-api

bba8875

Merge branch 'set-destructor-variant' into python-target-api

6075728

update time api

b8fb84c

housengw force-pushed the python-target-api branch from f0339dc to b8fb84c Compare April 27, 2022 20:57

housengw added 2 commits April 27, 2022 14:11

Merge branch 'set-destructor-variant' into python-target-api

c3fd686

update c time api and change tests

256cfae

housengw marked this pull request as ready for review April 28, 2022 00:05

housengw changed the base branch from set-destructor-variant to master April 28, 2022 00:05

Soroosh129 approved these changes Apr 28, 2022

View reviewed changes

housengw merged commit 7c66165 into master Apr 28, 2022

housengw deleted the python-target-api branch May 2, 2022 17:09

housengw mentioned this pull request May 4, 2022

Disable pylint c-extension-no-member warning #1140

Merged

lhstrh mentioned this pull request May 10, 2022

Odd timing behavior on RPi 4 (Raspian) #1151

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Update Python target APIs to match the C target updates #1116

Update Python target APIs to match the C target updates #1116

housengw commented Apr 26, 2022 •

edited

Loading

lhstrh commented Apr 28, 2022

Soroosh129 left a comment

Arka2009 commented May 3, 2022

edwardalee commented May 3, 2022

Arka2009 commented May 3, 2022

housengw commented May 3, 2022

Soroosh129 commented May 3, 2022

Arka2009 commented May 4, 2022

housengw commented May 4, 2022 •

edited

Loading

Arka2009 commented May 4, 2022

lhstrh commented May 5, 2022

edwardalee commented May 5, 2022

Soroosh129 commented May 5, 2022

Arka2009 commented May 5, 2022

Arka2009 commented May 5, 2022

lhstrh commented May 5, 2022

Arka2009 commented May 5, 2022

edwardalee commented May 5, 2022

Soroosh129 commented May 5, 2022 •

edited

Loading

Arka2009 commented May 5, 2022

Soroosh129 commented May 6, 2022 •

edited

Loading

edwardalee commented May 6, 2022

Arka2009 commented May 6, 2022

Soroosh129 commented May 6, 2022

Arka2009 commented May 6, 2022

edwardalee commented May 6, 2022

Arka2009 commented May 6, 2022

Arka2009 commented May 6, 2022

edwardalee commented May 7, 2022

Soroosh129 commented May 7, 2022

Arka2009 commented May 7, 2022

Arka2009 commented May 7, 2022

Soroosh129 commented May 9, 2022

Update Python target APIs to match the C target updates #1116

Update Python target APIs to match the C target updates #1116

Conversation

housengw commented Apr 26, 2022 • edited Loading

lhstrh commented Apr 28, 2022

Soroosh129 left a comment

Choose a reason for hiding this comment

Arka2009 commented May 3, 2022

edwardalee commented May 3, 2022

Arka2009 commented May 3, 2022

housengw commented May 3, 2022

Soroosh129 commented May 3, 2022

Arka2009 commented May 4, 2022

housengw commented May 4, 2022 • edited Loading

Arka2009 commented May 4, 2022

lhstrh commented May 5, 2022

edwardalee commented May 5, 2022

Soroosh129 commented May 5, 2022

Arka2009 commented May 5, 2022

Arka2009 commented May 5, 2022

lhstrh commented May 5, 2022

Arka2009 commented May 5, 2022

edwardalee commented May 5, 2022

Soroosh129 commented May 5, 2022 • edited Loading

Arka2009 commented May 5, 2022

Soroosh129 commented May 6, 2022 • edited Loading

edwardalee commented May 6, 2022

Arka2009 commented May 6, 2022

Soroosh129 commented May 6, 2022

Arka2009 commented May 6, 2022

edwardalee commented May 6, 2022

Arka2009 commented May 6, 2022

Arka2009 commented May 6, 2022

edwardalee commented May 7, 2022

Soroosh129 commented May 7, 2022

Arka2009 commented May 7, 2022

Arka2009 commented May 7, 2022

Soroosh129 commented May 9, 2022

housengw commented Apr 26, 2022 •

edited

Loading

housengw commented May 4, 2022 •

edited

Loading

Soroosh129 commented May 5, 2022 •

edited

Loading

Soroosh129 commented May 6, 2022 •

edited

Loading