Xinne/osc4py3

'osc_process()' throws "ValueError: list.remove(x): x not in list" for incomplete send command ('as_eventloop')

Opened this issue · 4 comments

vivi90 commented

Example script

#!/usr/bin/env python3
# -*- coding: utf-8 -*-
# SPDX-License-Identifier: AGPL-3.0-or-later

"""OSC bug example."""

# Logging
from logging import (
    basicConfig as set_logger_config,
    getLogger as get_logger,
    DEBUG as LOGLEVEL_DEBUG
)
from typing import Any
from osc4py3.as_eventloop import (
    osc_startup,
    osc_udp_server,
    osc_method,
    osc_udp_client,
    osc_send,
    osc_process,
    osc_terminate
)
from osc4py3.oscbuildparse import OSCMessage
from osc4py3.oscchannel import get_channel

FRM = "%(asctime)s - %(threadName)s ø %(name)s - %(levelname)s - %(message)s"
set_logger_config(
    filename="osc.log",
    filemode='a',
    encoding="utf-8",
    format=FRM
)
logger = get_logger("osc")
logger.setLevel(LOGLEVEL_DEBUG)


def received(*args: Any):
    """Receive transmission."""
    print("ONE")
    print(args)


def received2(*args: Any):
    """Receive transmission."""
    print("TWO")
    print(args)


osc_startup(logger=logger)

# Receiver
receiver: str = "receiver"
osc_udp_server(
    "127.0.0.1",
    39539,
    receiver
)
osc_method("/test/one", received)
osc_method("/test/one", received2)

# Sender
sender: str = "sender"
osc_udp_client(
    "127.0.0.1",
    39539,
    sender
)
osc_send(OSCMessage("/test/one", ",sif", ["first", 672, 8.871]), sender)
osc_process()
get_channel(sender).terminate()

try:
    while True:
        osc_process()  # throws ValueError: list.remove(x): x not in list
except KeyboardInterrupt:
    print("Canceled.")
finally:
    osc_terminate()

The message is sent and successfully received:

ONE
('first', 672, 8.871000289916992)
TWO
('first', 672, 8.871000289916992)

But it raises an ValueError: list.remove(x): x not in list after it.
The documentation says about osc_process():

[..] when running the system with `osc4py3.as_eventloop`, several calls to `osc_process()` may be necessary to achieve complete processing of message sending [..]

So this issue is not an surprise.
But if i am using as_comthreads or as_allthreads the error disappears and nothing is sent. 🙁
It would be great if it closes the channel only after everything is sent and completely processed.

I need this functionality for implementing an context manager object.

Interesting note: Even if i omit the line get_channel(sender).terminate(), it doesn't work at all with as_comthreads for me 🤔

Log

2022-07-25 03:28:18,931 - MainThread ø osc - DEBUG - monitor 2369057625936 created (SelectSocketMonitor).
2022-07-25 03:28:18,932 - MainThread ø osc - INFO - OSC channel 'receiver' setup as reader.
2022-07-25 03:28:18,933 - MainThread ø osc - DEBUG - OSC opening channel 'receiver'.
2022-07-25 03:28:18,934 - MainThread ø osc - INFO - UDP channel 'receiver' open read on AddrInfo(family=<AddressFamily.AF_INET: 2>, socktype=<SocketKind.SOCK_DGRAM: 2>, proto=17, canonname='127.0.0.1:39539', sockaddr=('127.0.0.1', 39539)).
2022-07-25 03:28:18,934 - MainThread ø osc - INFO - OSC channel 'receiver' activated.
2022-07-25 03:28:18,934 - MainThread ø osc - DEBUG - OSC scheduling channel 'receiver'.
2022-07-25 03:28:18,934 - MainThread ø osc - DEBUG - monitor 2369057625936 req add channel 736->receiver for r.
2022-07-25 03:28:18,934 - MainThread ø osc - INFO - OSC channel 'receiver' scheduled.
2022-07-25 03:28:18,935 - MainThread ø osc - INFO - OSC channel 'sender' setup as writer.
2022-07-25 03:28:18,935 - MainThread ø osc - DEBUG - OSC opening channel 'sender'.
2022-07-25 03:28:18,935 - MainThread ø osc - INFO - UDP channel 'sender' open write on ('0.0.0.0', 0) target AddrInfo(family=<AddressFamily.AF_INET: 2>, socktype=<SocketKind.SOCK_DGRAM: 2>, proto=17, canonname='127.0.0.1:39539', sockaddr=('127.0.0.1', 39539)).
2022-07-25 03:28:18,935 - MainThread ø osc - INFO - OSC channel 'sender' activated.
2022-07-25 03:28:18,935 - MainThread ø osc - DEBUG - OSC scheduling channel 'sender'.
2022-07-25 03:28:18,935 - MainThread ø osc - INFO - OSC channel 'sender' scheduled.
2022-07-25 03:28:18,936 - MainThread ø osc - DEBUG - OSC send packets processing SendingPacket(packet=OSCMessage(addrpattern='/test/one', typetags=',sif', arguments=['first', 672, 8.871]), packopt=<osc4py3.oscpacketoptions.PacketOptions object at 0x0000022796D6A2C0>, targets={'sender'})
2022-07-25 03:28:18,936 - MainThread ø osc - DEBUG - OSC packet_send_function to targets {'sender'} with OSCMessage(addrpattern='/test/one', typetags=',sif', arguments=['first', 672, 8.871])
2022-07-25 03:28:18,936 - MainThread ø osc - DEBUG - OSC transmit_rawpacket to channels {'sender'}
2022-07-25 03:28:18,937 - MainThread ø osc - DEBUG - OSC channel 'sender' transmit_data via write_pending queue
2022-07-25 03:28:18,937 - MainThread ø osc - DEBUG - OSC channel 'sender' another write packet available
2022-07-25 03:28:18,937 - MainThread ø osc - DEBUG - OSC channel 'sender' schedule of packet to write
2022-07-25 03:28:18,937 - MainThread ø osc - DEBUG - UDP sendto(bytearray(b'/test/one\x00\x00\x00,sif\x00\x00\x00\x00first\x00\x00\x00\x00\x00\x02\xa0A\r\xef\x9e') (...), ('127.0.0.1', 39539))
2022-07-25 03:28:18,937 - MainThread ø osc - DEBUG - OSC channel 'sender' monitoring set to True
2022-07-25 03:28:18,937 - MainThread ø osc - DEBUG - monitor 2369057625936 req add channel 768->sender for w.
2022-07-25 03:28:18,937 - MainThread ø osc - INFO - monitor 2369057625936 added channel receiver for r.
2022-07-25 03:28:18,938 - MainThread ø osc - INFO - monitor 2369057625936 added channel sender for w.
2022-07-25 03:28:18,938 - MainThread ø osc - DEBUG - monitor 2369057625936 detected r on channel receiver.
2022-07-25 03:28:18,938 - MainThread ø osc - DEBUG - UDP channel 'receiver' trigged for transmissions. r
2022-07-25 03:28:18,938 - MainThread ø osc - INFO - OSC channel 'receiver' receive packet from ('127.0.0.1', 61821): b'/test/one\x00\x00\x00,sif\x00\x00\x00\x00first\x00\x00\x00\x00\x00\x02\xa0A\r\xef\x9e'
2022-07-25 03:28:18,938 - MainThread ø osc - DEBUG - OSC raw packet processing ReceivedPacket(rawosc=b'/test/one\x00\x00\x00,sif\x00\x00\x00\x00first\x00\x00\x00\x00\x00\x02\xa0A\r\xef\x9e', packopt=<osc4py3.oscpacketoptions.PacketOptions object at 0x0000022796D6A380>)
2022-07-25 03:28:18,939 - MainThread ø osc - DEBUG - OSC dispatcher global found 2 matchs for message OSCMessage(addrpattern='/test/one', typetags=',sif', arguments=('first', 672, 8.871000289916992))
2022-07-25 03:28:18,940 - MainThread ø osc - DEBUG - OSC unscheduling channel 'sender'.
2022-07-25 03:28:18,940 - MainThread ø osc - DEBUG - monitor 2369057625936 request to remove channel sender for w.
2022-07-25 03:28:18,940 - MainThread ø osc - INFO - OSC channel 'sender' unscheduled.
2022-07-25 03:28:18,940 - MainThread ø osc - DEBUG - OSC closing channel 'sender'.
2022-07-25 03:28:18,940 - MainThread ø osc - INFO - UDP channel 'sender' closed.
2022-07-25 03:28:18,940 - MainThread ø osc - INFO - OSC channel 'sender' deactivated.
2022-07-25 03:28:18,941 - MainThread ø osc - INFO - monitor 2369057625936 removed channel sender for w.
2022-07-25 03:28:18,941 - MainThread ø osc - DEBUG - monitor 2369057625936 detected w on channel sender.
2022-07-25 03:28:18,941 - MainThread ø osc - DEBUG - UDP channel 'sender' trigged for transmissions. w
2022-07-25 03:28:18,941 - MainThread ø osc - DEBUG - OSC channel 'sender' notification of written packet
2022-07-25 03:28:18,942 - MainThread ø osc - DEBUG - OSC channel 'sender' monitoring set to False
2022-07-25 03:28:18,942 - MainThread ø osc - DEBUG - monitor 2369057625936 request to remove channel sender for w.
2022-07-25 03:28:18,942 - MainThread ø osc - DEBUG - OSC unscheduling channel 'receiver'.
2022-07-25 03:28:18,942 - MainThread ø osc - DEBUG - monitor 2369057625936 request to remove channel receiver for r.
2022-07-25 03:28:18,942 - MainThread ø osc - INFO - OSC channel 'receiver' unscheduled.
2022-07-25 03:28:18,942 - MainThread ø osc - DEBUG - OSC closing channel 'receiver'.
2022-07-25 03:28:18,942 - MainThread ø osc - INFO - UDP channel 'receiver' closed.
2022-07-25 03:28:18,943 - MainThread ø osc - INFO - OSC channel 'receiver' deactivated.
2022-07-25 03:28:18,943 - MainThread ø osc - DEBUG - monitor 2369057625936 request to terminate.

System

  • osc4py3: 1.0.8
  • Python: 3.10.4
  • OS: Windows 10 Enterprise Version 21H2 (Build 19044.1826)
vivi90 commented

Interesting note: Even if i omit the line get_channel(sender).terminate(), it doesn't work at all with as_comthreads for me 🤔

[..]

  • osc4py3: 1.0.8

[..]

Because of #11.

vivi90 commented

With an downgrade to version 1.0.3 of osc4py3 the ValueError disappears.
Also my example code works with as_eventloop, but not with as_comthreads.
So osc4py3 is still not usable with context managers.

lpointal commented

Hello,
I did some investigations. do_fileno_removed() is called twice, second time with fileno having None value.
Until I fix it in the correct place, you can use a workaround, at the begining of SelectSocketMonitor.do_fileno_removed(), simply add

        if fileno is None: 
            return

Note: this bug wasn't trigged with older versions… as they dont care of correct termination — it was initially intended to setup communications and communicate, not setup/clean/setup/clean… but some users did that so I had to manage it.

Note2: I maintain sources on sourcesup, not github.

  • 👍1
vivi90 commented

@lpointal Great, thank you! 😃 Looking forward to your fixed release on PyPi.

[..] do_fileno_removed() is called twice, second time with fileno having None value. [..]

Makes sense.

[..] wasn't trigged with older versions [..]

I see.

[..] I maintain sources on sourcesup, not github.

Okay, i understand.
This github repo (mirror?) is just the number one landing place on google and i am not the first person posting here issues.
So my feeling was, it's okay to ask here.
Btw., if i am free to make an proposal.. how about CodeBerg (Non-profit, EU) as an possible new source code home?
Because unfortunately i am no french student, so i am not able to contribute on sourcesup.