logging/example_logging.py

@@ -1,6 +1,46 @@
+import os
+import time
 import logging
 
+
+def reset_log(log_file):
+    try:
+        os.remove(log_file)
+    except OSError:
+        pass
+
+
+def stress_test(iterations):
+    sample = "All work and no play, makes Jack a dull boy!"
+    log_file = 'file.log'
+    reset_log(log_file)
+    logging.basicConfig(filename=log_file)
+    start_time = time.time()
+    for i in range(iterations):
+        logging.info("%d %s" % (i, sample))
+    file_delta = time.time() - start_time
+    reset_log(log_file)
+
+    logging.basicConfig(filename=None)
+    start_time = time.time()
+    for i in range(iterations):
+        logging.info("%d %s" % (i, sample))
+    stdout_delta = time.time() - start_time
+    print("File logging time %f for %i iterations" % (file_delta, iterations))
+    print("Stdout logging time %f for %i iterations" % (stdout_delta, iterations))
+
+
 logging.basicConfig(level=logging.INFO)
 log = logging.getLogger("test")
 log.debug("Test message: %d(%s)", 100, "foobar")
 log.info("Test message2: %d(%s)", 100, "foobar")
+
+log.warning("Test message3: %d(%s)")
+log.error("Test message4")
+log.critical("Test message5")
+logging.info("Test message6")
+
+try:
+    1/0
+except:
+    log.exception("Some trouble (%s)", "expected")

logging/logging.py

@@ -19,18 +19,35 @@
 
 class Logger:
 
+    level = NOTSET
+
     def __init__(self, name):
-        self.level = NOTSET
         self.name = name
 
     def _level_str(self, level):
-        if level in _level_dict:
-            return _level_dict[level]
-        return "LVL" + str(level)
+        l = _level_dict.get(level)
+        if l is not None:
+            return l
+        return "LVL%s" % level
+
+    def setLevel(self, level):
+        self.level = level
+
+    def isEnabledFor(self, level):
+        return level >= (self.level or _level)
 
     def log(self, level, msg, *args):
         if level >= (self.level or _level):
-            print(("%s:%s:" + msg) % ((self._level_str(level), self.name) + args), file=_stream)
+            if _log_file:
+                _log_file.write(("%s:%s:" + msg + "\n") % ((self._level_str(level), self.name) + args))
+                _log_file.flush()
+            else:
+                _stream.write("%s:%s:" % (self._level_str(level), self.name))
+                if not args:
+                    print(msg, file=_stream)
+                else:
+                    print(msg % args, file=_stream)
+
 
     def debug(self, msg, *args):
         self.log(DEBUG, msg, *args)
@@ -47,9 +64,17 @@ def error(self, msg, *args):
     def critical(self, msg, *args):
         self.log(CRITICAL, msg, *args)
 
+    def exc(self, e, msg, *args):
+        self.log(ERROR, msg, *args)
+        sys.print_exception(e, _stream)
+
+    def exception(self, msg, *args):
+        self.exc(sys.exc_info()[1], msg, *args)
+
 
 _level = INFO
 _loggers = {}
+_log_file = None
 
 def getLogger(name):
     if name in _loggers:
@@ -65,11 +90,12 @@ def debug(msg, *args):
     getLogger(None).debug(msg, *args)
 
 def basicConfig(level=INFO, filename=None, stream=None, format=None):
-    global _level, _stream
+    global _level, _stream, _log_file
     _level = level
-    if stream:
-        _stream = stream
-    if filename is not None:
-        print("logging.basicConfig: filename arg is not supported")
+    if filename:
+        _log_file = open(filename, 'a')
+    else:
+        if stream:
+            _stream = stream
     if format is not None:
         print("logging.basicConfig: format arg is not supported")

logging/metadata.txt

@@ -1,3 +1,3 @@
 srctype = micropython-lib
 type = module
-version = 0.1.3
+version = 0.3

logging/setup.py

@@ -7,7 +7,7 @@
 import sdist_upip
 
 setup(name='micropython-logging',
-      version='0.1.3',
+      version='0.3',
       description='logging module for MicroPython',
       long_description="This is a module reimplemented specifically for MicroPython standard library,\nwith efficient and lean design in mind. Note that this module is likely work\nin progress and likely supports just a subset of CPython's corresponding\nmodule. Please help with the development if you are interested in this\nmodule.",
       url='https://github.com/micropython/micropython-lib',

logging/test_logging.py

@@ -0,0 +1,37 @@
+import logging
+import os
+
+
+def reset_log(log_file):
+    try:
+        os.remove(log_file)
+    except OSError:
+        pass
+
+
+def test_basicConfig():
+    print("Testing logging.basicConfig")
+    log_file = 'file.log'
+    log_message = '123'
+
+    reset_log(log_file)
+    logging.basicConfig(filename=log_file)
+    logging.info(log_message)
+
+    with open(log_file, 'r') as logf:
+        assert log_message in logf.read()
+
+    print("Success: Testing logging.basicConfig")
+
+
+tests = [test_basicConfig]
+
+
+def test():
+    print("Running %i tests." % len(tests))
+    for test_function in tests:
+        test_function()
+
+
+if __name__ == '__main__':
+    test()

uasyncio.core/metadata.txt

@@ -1,6 +1,6 @@
 srctype = micropython-lib
 type = package
-version = 1.7.2
+version = 2.0
 author = Paul Sokolovsky
 desc = Lightweight asyncio-like library for MicroPython, built around native Python coroutines. (Core event loop).
 long_desc = Lightweight asyncio-like library for MicroPython, built around native Python coroutines. (Core event loop).

uasyncio.core/setup.py

@@ -7,7 +7,7 @@
 import sdist_upip
 
 setup(name='micropython-uasyncio.core',
-      version='1.7.2',
+      version='2.0',
       description='Lightweight asyncio-like library for MicroPython, built around native Python coroutines. (Core event loop).',
       long_description='Lightweight asyncio-like library for MicroPython, built around native Python coroutines. (Core event loop).',
       url='https://github.com/micropython/micropython-lib',

uasyncio.core/test_full_wait.py

@@ -47,4 +47,4 @@ def cb_2nd():
 print(loop.msgs)
 # .wait() is now called on each loop iteration, and for our mock case, it means that
 # at the time of running, self.time() will be skewed by 100 virtual time units.
-assert loop.msgs == ['I should be run first, time: 200', 'I should be run second, time: 600'], str(loop.msgs)
+assert loop.msgs == ['I should be run first, time: 100', 'I should be run second, time: 500'], str(loop.msgs)

uasyncio.core/uasyncio/core.py

@@ -1,5 +1,6 @@
 import utime as time
 import utimeq
+import ucollections
 
 
 type_gen = type((lambda: (yield))())
@@ -25,8 +26,9 @@ class TimeoutError(CancelledError):
 
 class EventLoop:
 
-    def __init__(self, len=42):
-        self.q = utimeq.utimeq(len)
+    def __init__(self, runq_len=16, waitq_len=16):
+        self.runq = ucollections.deque((), runq_len, True)
+        self.waitq = utimeq.utimeq(waitq_len)
         # Current task being run. Task is a top-level coroutine scheduled
         # in the event loop (sub-coroutines executed transparently by
         # yield from/await, event loop "doesn't see" them).
@@ -41,18 +43,24 @@ def create_task(self, coro):
         # CPython asyncio incompatibility: we don't return Task object
 
     def call_soon(self, callback, *args):
-        self.call_at_(self.time(), callback, args)
+        if __debug__ and DEBUG:
+            log.debug("Scheduling in runq: %s", (callback, args))
+        self.runq.append(callback)
+        if not isinstance(callback, type_gen):
+            self.runq.append(args)
 
     def call_later(self, delay, callback, *args):
         self.call_at_(time.ticks_add(self.time(), int(delay * 1000)), callback, args)
 
     def call_later_ms(self, delay, callback, *args):
+        if not delay:
+            return self.call_soon(callback, *args)
         self.call_at_(time.ticks_add(self.time(), delay), callback, args)
 
     def call_at_(self, time, callback, args=()):
         if __debug__ and DEBUG:
-            log.debug("Scheduling %s", (time, callback, args))
-        self.q.push(time, callback, args)
+            log.debug("Scheduling in waitq: %s", (time, callback, args))
+        self.waitq.push(time, callback, args)
 
     def wait(self, delay):
         # Default wait implementation, to be overriden in subclasses
@@ -64,45 +72,45 @@ def wait(self, delay):
     def run_forever(self):
         cur_task = [0, 0, 0]
         while True:
-            if self.q:
-                # wait() may finish prematurely due to I/O completion,
-                # and schedule new, earlier than before tasks to run.
-                while 1:
-                    t = self.q.peektime()
-                    tnow = self.time()
-                    delay = time.ticks_diff(t, tnow)
-                    if delay < 0:
-                        delay = 0
-                    # Always call wait(), to give a chance to I/O scheduling
-                    self.wait(delay)
-                    if delay == 0:
-                        break
-
-                self.q.pop(cur_task)
-                t = cur_task[0]
-                cb = cur_task[1]
-                args = cur_task[2]
+            # Expire entries in waitq and move them to runq
+            tnow = self.time()
+            while self.waitq:
+                t = self.waitq.peektime()
+                delay = time.ticks_diff(t, tnow)
+                if delay > 0:
+                    break
+                self.waitq.pop(cur_task)
+                if __debug__ and DEBUG:
+                    log.debug("Moving from waitq to runq: %s", cur_task[1])
+                self.call_soon(cur_task[1], *cur_task[2])
+
+            # Process runq
+            l = len(self.runq)
+            if __debug__ and DEBUG:
+                log.debug("Entries in runq: %d", l)
+            while l:
+                cb = self.runq.popleft()
+                l -= 1
+                args = ()
+                if not isinstance(cb, type_gen):
+                    args = self.runq.popleft()
+                    l -= 1
+                    if __debug__ and DEBUG:
+                        log.info("Next callback to run: %s", (cb, args))
+                    cb(*args)
+                    continue
+
                 if __debug__ and DEBUG:
-                    log.debug("Next coroutine to run: %s", (t, cb, args))
+                    log.info("Next coroutine to run: %s", (cb, args))
                 self.cur_task = cb
-#                __main__.mem_info()
-            else:
-                self.wait(-1)
-                # Assuming IO completion scheduled some tasks
-                continue
-            if callable(cb):
-                cb(*args)
-            else:
                 delay = 0
                 try:
-                    if __debug__ and DEBUG:
-                        log.debug("Coroutine %s send args: %s", cb, args)
-                    if args == ():
+                    if args is ():
                         ret = next(cb)
                     else:
                         ret = cb.send(*args)
                     if __debug__ and DEBUG:
-                        log.debug("Coroutine %s yield result: %s", cb, ret)
+                        log.info("Coroutine %s yield result: %s", cb, ret)
                     if isinstance(ret, SysCall1):
                         arg = ret.arg
                         if isinstance(ret, SleepMs):
@@ -147,7 +155,22 @@ def run_forever(self):
                 # Currently all syscalls don't return anything, so we don't
                 # need to feed anything to the next invocation of coroutine.
                 # If that changes, need to pass that value below.
-                self.call_later_ms(delay, cb)
+                if delay:
+                    self.call_later_ms(delay, cb)
+                else:
+                    self.call_soon(cb)
+
+            # Wait until next waitq task or I/O availability
+            delay = 0
+            if not self.runq:
+                delay = -1
+                if self.waitq:
+                    tnow = self.time()
+                    t = self.waitq.peektime()
+                    delay = time.ticks_diff(t, tnow)
+                    if delay < 0:
+                        delay = 0
+            self.wait(delay)
 
     def run_until_complete(self, coro):
         def _run_and_stop():
@@ -195,10 +218,10 @@ class IOWriteDone(SysCall1):
 
 _event_loop = None
 _event_loop_class = EventLoop
-def get_event_loop(len=42):
+def get_event_loop(runq_len=16, waitq_len=16):
     global _event_loop
     if _event_loop is None:
-        _event_loop = _event_loop_class(len)
+        _event_loop = _event_loop_class(runq_len, waitq_len)
     return _event_loop
 
 def sleep(secs):

uasyncio.udp/metadata.txt

@@ -1,6 +1,6 @@
 srctype = micropython-lib
 type = package
-version = 0.1
+version = 0.1.1
 author = Paul Sokolovsky
 desc = UDP support for MicroPython's uasyncio
 depends = uasyncio

uasyncio.udp/setup.py

@@ -7,7 +7,7 @@
 import sdist_upip
 
 setup(name='micropython-uasyncio.udp',
-      version='0.1',
+      version='0.1.1',
       description="UDP support for MicroPython's uasyncio",
       long_description="This is a module reimplemented specifically for MicroPython standard library,\nwith efficient and lean design in mind. Note that this module is likely work\nin progress and likely supports just a subset of CPython's corresponding\nmodule. Please help with the development if you are interested in this\nmodule.",
       url='https://github.com/micropython/micropython-lib',

uasyncio.udp/uasyncio/udp.py

@@ -45,7 +45,7 @@ def recvfrom(s, n):
 
 def sendto(s, buf, addr=None):
     while 1:
-        res = s.sendto(buf, 0, addr)
+        res = s.sendto(buf, addr)
         #print("send res:", res)
         if res == len(buf):
             return

uasyncio/benchmark/boom_uasyncio.py

@@ -19,7 +19,7 @@ def validate(resp):
     no = int(l.split()[1])
     seen.append(no)
     c = t.count(l + "\r\n")
-    assert c == 400101
+    assert c == 400101, str(c)
     assert t.endswith("=== END ===")
 
     cnt += 1