Jump to content

brickd liefert Fehlermeldungen am laufenden Band


Recommended Posts

Hallo,

derzeit bin ich dabei per buildroot (https://buildroot.org/) ein Embedded Linux Image für den Raspberry Pi Zero zu bauen.

Das Image wird sehr minimalistisch und erstmal nur brickd beinhalten. Die eigentliche Applikation wird remote gestartet.

Für die Anschlüsse der Bricklets verwende ich Tinkerforge HAT Zero 1.0 und einen RPi Zero mit USB Ethernet Schnittstelle.

Wenn ich brickd starte, bekomme ich in einer rasenden Geschwindigkeit immer wieder diese Fehlermeldung:

 

Quote

<E> <bricklet_stack.c:506> Message packet error (port: E, count: 1), invalid response: Invalid UID

 

Wie kommt es zu diesen Meldungen? Was kann ich tun?

Ist Port E der Port vom HAT selbst? Denn Bricklet Anschlüsse hat das HAT Zero nur vier, also bis Port D.

Besten Gruß und vielen Dank für jegliche Hilfe.

 

So sieht die brickd.conf aus  (grep -v \# /etc/brickd.conf|sort):

Quote

authentication.secret =
bricklet.group0.cs0.driver = gpio
bricklet.group0.cs0.name = gpio27
bricklet.group0.cs0.num = 27
bricklet.group0.cs1.driver = gpio
bricklet.group0.cs1.name = gpio23
bricklet.group0.cs1.num = 23
bricklet.group0.cs2.driver = gpio
bricklet.group0.cs2.name = gpio24
bricklet.group0.cs2.num = 24
bricklet.group0.cs3.driver = gpio
bricklet.group0.cs3.name = gpio22
bricklet.group0.cs3.num = 22
bricklet.group0.cs4.driver = gpio
bricklet.group0.cs4.name = gpio25
bricklet.group0.cs4.num = 25
bricklet.group0.spidev = /dev/spidev0.0
listen.address = 0.0.0.0
listen.dual_stack = off
listen.mesh_gateway_port = 4240
listen.plain_port = 4223
listen.websocket_port = 0
log.debug_filter =
log.level = info

Und die Ausgaben von brickd --debug:

Quote

2020-12-28 19:18:46.777908 <I> <main_linux.c:367> Brick Daemon 2.4.3 started (pid: 142, daemonized: 0)
2020-12-28 19:18:46.781431 <D> <main_linux.c:375> Using config file: /etc/brickd.conf
2020-12-28 19:18:46.784435 <D> <main_linux.c:381> Using PID file: /var/run/brickd.pid
2020-12-28 19:18:46.787418 <D> <event.c:60> Initializing event subsystem
2020-12-28 19:18:46.790516 <D> <event|event.c:270> Added generic event source (handle: 5, name: event-stop, events: 0x0001) at index 0
2020-12-28 19:18:46.792595 <D> <event|event.c:270> Added generic event source (handle: 7, name: signal, events: 0x0001) at index 1
2020-12-28 19:18:46.794632 <D> <hardware.c:39> Initializing hardware subsystem
2020-12-28 19:18:46.797699 <D> <usb.c:261> Initializing USB subsystem
2020-12-28 19:18:46.799811 <D> <usb_posix.c:188> Successfully loaded brickd (for libusb symbols)
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000071] [0000008e] libusb: debug [libusb_init] created default context
[ 0.006734] [0000008e] libusb: debug [libusb_init] libusb v1.0.23.11397
[ 0.009018] [0000008e] libusb: debug [find_usbfs_path] found usbfs at /dev/bus/usb
[ 0.010712] [0000008e] libusb: debug [get_kernel_version] reported kernel version is 5.4.72
[ 0.013858] [0000008e] libusb: debug [op_init] bulk continuation flag supported
[ 0.014475] [0000008e] libusb: debug [op_init] zero length packet flag supported
[ 0.015949] [0000008e] libusb: debug [op_init] max iso packet length is (likely) 49152 bytes
[ 0.018399] [0000008e] libusb: debug [op_init] sysfs can relate devices
[ 0.019977] [0000008e] libusb: debug [op_init] sysfs has complete descriptors
[ 0.023339] [0000008e] libusb: debug [linux_get_device_address] getting address for device: usb1 detached: 0
[ 0.027857] [0000008e] libusb: debug [linux_get_device_address] scan usb1
[ 0.030590] [0000008e] libusb: debug [linux_get_device_address] bus=1 dev=1
[ 0.033368] [0000008e] libusb: debug [linux_enumerate_device] busnum 1 devaddr 1 session_id 257
[ 0.036115] [0000008e] libusb: debug [linux_enumerate_device] allocating new device for 1/1 (session 257)
[ 0.039526] [0000008e] libusb: debug [linux_get_device_address] getting address for device: 1-1 detached: 0
[ 0.033207] [00000090] libusb: debug [linux_netlink_event_thread_main] netlink event thread entering
[ 0.043392] [0000008e] libusb: debug [linux_get_device_address] scan 1-1
[ 0.046860] [0000008e] libusb: debug [linux_get_device_address] bus=1 dev=2
[ 0.048555] [0000008e] libusb: debug [linux_enumerate_device] busnum 1 devaddr 2 session_id 258
[ 0.051506] [0000008e] libusb: debug [linux_enumerate_device] allocating new device for 1/2 (session 258)
[ 0.054223] [0000008e] libusb: debug [linux_get_parent_info] Dev 0x6023e8 (1-1) has parent 0x602730 (usb1) port 1
[ 0.057147] [0000008e] libusb: debug [linux_get_device_address] getting address for device: 1-1.4 detached: 0
[ 0.058992] [0000008e] libusb: debug [linux_get_device_address] scan 1-1.4
[ 0.061935] [0000008e] libusb: debug [linux_get_device_address] bus=1 dev=3
[ 0.064834] [0000008e] libusb: debug [linux_enumerate_device] busnum 1 devaddr 3 session_id 259
[ 0.066350] [0000008e] libusb: debug [linux_enumerate_device] allocating new device for 1/3 (session 259)
[ 0.068022] [0000008e] libusb: debug [linux_get_parent_info] Dev 0x6021f0 (1-1.4) has parent 0x6023e8 (1-1) port 4
[ 0.071457] [0000008e] libusb: debug [usbi_add_pollfd] add fd 12 events 1
[ 0.073577] [0000008e] libusb: debug [usbi_io_init] using timerfd for timeouts
[ 0.076383] [0000008e] libusb: debug [usbi_add_pollfd] add fd 14 events 1
2020-12-28 19:18:46.879905 <D> <event|event.c:270> Added USB event source (handle: 12, name: usb-poll, events: 0x0001) at index 2
2020-12-28 19:18:46.881910 <D> <event|event.c:270> Added USB event source (handle: 14, name: usb-poll, events: 0x0001) at index 3
2020-12-28 19:18:46.885093 <D> <usb.c:323> libusb supports hotplug
[ 0.084811] [0000008e] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 0x6026e0 with handle 1
[ 0.087355] [0000008e] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 0x6027b0 with handle 2
2020-12-28 19:18:46.890731 <D> <usb.c:334> Starting initial USB device scan
2020-12-28 19:18:46.894091 <D> <usb.c:385> Looking for added/removed USB devices
[ 0.093831] [0000008e] libusb: debug [libusb_get_device_list]
2020-12-28 19:18:46.898162 <D> <usb.c:114> Found 3 USB device(s)
[ 0.097930] [0000008e] libusb: debug [libusb_get_device_descriptor]
[ 0.100943] [0000008e] libusb: debug [libusb_get_device_descriptor]
[ 0.102422] [0000008e] libusb: debug [libusb_get_device_descriptor]
2020-12-28 19:18:46.904815 <D> <network.c:177> Initializing network subsystem
2020-12-28 19:18:46.905021 <D> <socket.c:164> Opening server socket(s) for address '0.0.0.0' on port 4223
2020-12-28 19:18:46.905655 <D> <socket.c:264> Started listening to '0.0.0.0' (IPv4) resolved from '0.0.0.0' on port 4223
2020-12-28 19:18:46.905865 <D> <event|event.c:270> Added generic event source (handle: 15, name: server, events: 0x0001) at index 4
2020-12-28 19:18:46.905998 <D> <mesh.c:53> Initializing mesh subsystem
2020-12-28 19:18:46.906117 <D> <socket.c:164> Opening server socket(s) for address '0.0.0.0' on port 4240
2020-12-28 19:18:46.906420 <D> <socket.c:264> Started listening to '0.0.0.0' (IPv4) resolved from '0.0.0.0' on port 4240
2020-12-28 19:18:46.906582 <D> <event|event.c:270> Added generic event source (handle: 16, name: mesh-server, events: 0x0001) at index 5
2020-12-28 19:18:46.907130 <I> <bricklet.c:270> Found supported HAT product_id 0x085d in device tree, using default HAT Zero Brick config
2020-12-28 19:18:46.914013 <I> <bricklet.c:311> Found Bricklet port A (spidev: /dev/spidev0.0, driver: gpio, name: gpio27, num: 27)
2020-12-28 19:18:46.915687 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port A
2020-12-28 19:18:46.918233 <D> <event|event.c:270> Added generic event source (handle: 17, name: bricklet-stack-notification, events: 0x0001) at index 6
2020-12-28 19:18:46.920485 <I> <bricklet_stack_linux.c:129> Using BCM2835 backend for Bricklets (Raspberry Pi detected)
2020-12-28 19:18:46.929369 <D> <bricklet_stack_linux_bcm2835.c:80> Raspberry Pi core_freq_min value is zero, assuming 250 MHz
2020-12-28 19:18:46.932405 <W> <bricklet_stack_linux_bcm2835.c:129> Raspberry Pi core frequency (core_freq: 400, core_freq_min: 250) is unstable, SPI throughput will be unstable too
2020-12-28 19:18:46.935208 <I> <bricklet_stack_linux_bcm2835.c:133> Using 400 MHz Raspberry Pi core frequency (core_freq: 400, core_freq_min: 250) for BCM2835 backend
2020-12-28 19:18:46.941229 <I> <bricklet.c:311> Found Bricklet port B (spidev: /dev/spidev0.0, driver: gpio, name: gpio23, num: 23)
2020-12-28 19:18:46.944257 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port B
2020-12-28 19:18:46.947679 <D> <event|event.c:270> Added generic event source (handle: 18, name: bricklet-stack-notification, events: 0x0001) at index 7
2020-12-28 19:18:46.951066 <I> <bricklet.c:311> Found Bricklet port C (spidev: /dev/spidev0.0, driver: gpio, name: gpio24, num: 24)
2020-12-28 19:18:46.953953 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port C
2020-12-28 19:18:46.956101 <D> <event|event.c:270> Added generic event source (handle: 19, name: bricklet-stack-notification, events: 0x0001) at index 8
2020-12-28 19:18:46.959660 <I> <bricklet.c:311> Found Bricklet port D (spidev: /dev/spidev0.0, driver: gpio, name: gpio22, num: 22)
2020-12-28 19:18:46.961798 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port D
2020-12-28 19:18:46.965168 <D> <event|event.c:270> Added generic event source (handle: 20, name: bricklet-stack-notification, events: 0x0001) at index 9
2020-12-28 19:18:46.968909 <I> <bricklet.c:311> Found Bricklet port E (spidev: /dev/spidev0.0, driver: gpio, name: gpio25, num: 25)
2020-12-28 19:18:46.971837 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port E
2020-12-28 19:18:46.973915 <D> <event|event.c:270> Added generic event source (handle: 21, name: bricklet-stack-notification, events: 0x0001) at index 10
2020-12-28 19:18:46.977701 <D> <event.c:534> Starting the event loop
2020-12-28 19:18:46.980658 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2020-12-28 19:18:46.982463 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2020-12-28 19:18:46.984440 <D> <event|event.c:447> Handling USB event source (handle: 12, name: usb-poll, received-events: 0x0001)
[ 0.184881] [0000008e] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.188007] [0000008e] libusb: debug [handle_events] poll fds modified, reallocating
[ 0.189667] [0000008e] libusb: debug [handle_events] poll() 2 fds with timeout in 0ms
[ 0.191506] [0000008e] libusb: debug [handle_events] poll() returned 0
2020-12-28 19:18:46.995761 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 1), invalid response: Invalid UID
2020-12-28 19:18:46.996114 <D> <event|event_linux.c:179> Handled all ready event sources
2020-12-28 19:18:47.000888 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2020-12-28 19:18:47.005555 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 2), invalid response: Invalid UID
2020-12-28 19:18:47.011659 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 3), invalid response: Invalid UID
2020-12-28 19:18:47.017811 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 4), invalid response: Invalid UID
2020-12-28 19:18:47.023016 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 5), invalid response: Invalid UID
2020-12-28 19:18:47.028267 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 6), invalid response: Invalid UID
2020-12-28 19:18:47.033464 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 7), invalid response: Invalid UID
2020-12-28 19:18:47.038679 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 8), invalid response: Invalid UID
2020-12-28 19:18:47.044800 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 9), invalid response: Invalid UID
2020-12-28 19:18:47.050094 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 10), invalid response: Invalid UID
2020-12-28 19:18:47.055480 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 11), invalid response: Invalid UID
2020-12-28 19:18:47.061570 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 12), invalid response: Invalid UID
2020-12-28 19:18:47.066800 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 13), invalid response: Invalid UID
2020-12-28 19:18:47.072155 <E> <bricklet_stack.c:506> Message packet error (port: E, count: 14), invalid response: Invalid UID

 

 

Edited by lapawa
Link to post
Share on other sites

Moin,

Ja, Port E ist der vom HAT selbst. Das Problem, dass du da hast scheint ein Bug in der aktuellen Version von Brick Daemon zu sein, ist z.B. hier schon mal aufgetaucht. @photron ist noch im Weihnachtsurlaub, aber in den nächsten Wochen fixen wir das.

Edit: Als Work-Around kannst du auch probieren, ob Brick Daemon 2.4.1 bei dir das Problem nicht erzeugt. Der braucht aber udev oder ähnliches.

Link to post
Share on other sites
Posted (edited)

Die version 2.4.1 hat mir nur ein Stückchen weitergeholfen.

Die Fehlermeldungen sind weg. Eine Verbindung per brickv funktioniert. Jedoch werden weder brick noch bricklets im brickv angezeigt.

Diesmal habe ich zusätzlich zum Debug Log noch eine Strace Auszug erstelt.

Was mir auffällt ist,

  • dass brickd ständig write Zugriffe auf libusb ausführt. Und dies obwohl das HAT per SPI mit den Bricklets kommuniziert.
  • dass die GPIO Exports beim Beenden von brickd nicht wieder beim Kernel abgemeldet werden.
  • Zugriff auf die Zeitzonen datei /etc/localtime funktioniert nicht. Da sie nicht existiert.
    openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
    Ist dies ein Problem für brickd?
  • Das HAT wird erkannt:
    openat(AT_FDCWD, "/proc/device-tree/hat/product_id", O_RDONLY) = 17
    read(17, "0x085d", 6)                   = 6
    close(17)   
    2021-01-04 18:35:46.490397 <D> <bricklet.c:182> Found product_id "0x085d" in device tree, using pre-configured HAT Zero Brick setup
  • Die GPIOs für die Chip Select Signale der einzelnen Parts A-E werden beim Kernel als export angemeldet
    openat(AT_FDCWD, "/sys/class/gpio/export", O_WRONLY) = 18
    write(18, "27", 2)                      = 2
    close(18)                               = 0
    openat(AT_FDCWD, "/sys/class/gpio/gpio27/direction", O_WRONLY) = 18
    write(18, "out", 3)                     = 3
    close(18)                               = 0
    openat(AT_FDCWD, "/sys/class/gpio/gpio27/value", O_WRONLY) = 18
    write(18, "1", 1)                       = 1
    close(18)                               = 0
    openat(AT_FDCWD, "/sys/class/gpio/gpio27/value", O_WRONLY) = 18

Meine Frage hierzu: Kann der Kernel SPI Treiber das CS Timing nicht besser selbst erledigen? Clock und MasterOut kommt ja auch von dort, oder?

 

Debug Log:

Quote

# strace -o brickd-2.4.1.strace ./brickd-2.4.1 --debug
2021-01-04 18:35:46.260210 <I> <main_linux.c:334> Brick Daemon 2.4.1 started (pid: 147, daemonized: 0)
2021-01-04 18:35:46.266504 <D> <main_linux.c:342> Using config file: /etc/brickd.conf
2021-01-04 18:35:46.269294 <D> <main_linux.c:348> Using PID file: /var/run/brickd.pid
2021-01-04 18:35:46.272048 <D> <event.c:60> Initializing event subsystem
2021-01-04 18:35:46.275942 <D> <event|event.c:270> Added generic event source (handle: 5, name: event-stop, events: 0x0001) at index 0
2021-01-04 18:35:46.279570 <D> <event|event.c:270> Added generic event source (handle: 7, name: signal, events: 0x0001) at index 1
2021-01-04 18:35:46.284587 <D> <hardware.c:39> Initializing hardware subsystem
2021-01-04 18:35:46.287548 <D> <usb.c:258> Initializing USB subsystem
2021-01-04 18:35:46.290649 <D> <usb_posix.c:151> Successfully loaded brickd (for libusb symbols)
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000517] [00000093] libusb: debug [libusb_init] created default context
[ 0.007266] [00000093] libusb: debug [libusb_init] libusb v1.0.23.11397
[ 0.012475] [00000093] libusb: debug [find_usbfs_path] found usbfs at /dev/bus/usb
[ 0.016184] [00000093] libusb: debug [get_kernel_version] reported kernel version is 5.4.72
[ 0.018960] [00000093] libusb: debug [op_init] bulk continuation flag supported
[ 0.021976] [00000093] libusb: debug [op_init] zero length packet flag supported
[ 0.024666] [00000093] libusb: debug [op_init] max iso packet length is (likely) 49152 bytes
[ 0.028279] [00000093] libusb: debug [op_init] sysfs can relate devices
[ 0.031161] [00000093] libusb: debug [op_init] sysfs has complete descriptors
[ 0.039856] [00000093] libusb: debug [linux_get_device_address] getting address for device: usb1 detached: 0
[ 0.040575] [00000094] libusb: debug [linux_netlink_event_thread_main] netlink event thread entering
[ 0.044788] [00000093] libusb: debug [linux_get_device_address] scan usb1
[ 0.052990] [00000093] libusb: debug [linux_get_device_address] bus=1 dev=1
[ 0.055719] [00000093] libusb: debug [linux_enumerate_device] busnum 1 devaddr 1 session_id 257
[ 0.058500] [00000093] libusb: debug [linux_enumerate_device] allocating new device for 1/1 (session 257)
[ 0.065587] [00000093] libusb: debug [linux_get_device_address] getting address for device: 1-1 detached: 0
[ 0.068454] [00000093] libusb: debug [linux_get_device_address] scan 1-1
[ 0.075975] [00000093] libusb: debug [linux_get_device_address] bus=1 dev=2
[ 0.078763] [00000093] libusb: debug [linux_enumerate_device] busnum 1 devaddr 2 session_id 258
[ 0.081497] [00000093] libusb: debug [linux_enumerate_device] allocating new device for 1/2 (session 258)
[ 0.088630] [00000093] libusb: debug [linux_get_parent_info] Dev 0xd7a3e8 (1-1) has parent 0xd7a730 (usb1) port 1
[ 0.091388] [00000093] libusb: debug [linux_get_device_address] getting address for device: 1-1.4 detached: 0
[ 0.094111] [00000093] libusb: debug [linux_get_device_address] scan 1-1.4
[ 0.101955] [00000093] libusb: debug [linux_get_device_address] bus=1 dev=3
[ 0.104980] [00000093] libusb: debug [linux_enumerate_device] busnum 1 devaddr 3 session_id 259
[ 0.107715] [00000093] libusb: debug [linux_enumerate_device] allocating new device for 1/3 (session 259)
[ 0.114642] [00000093] libusb: debug [linux_get_parent_info] Dev 0xd7a1f0 (1-1.4) has parent 0xd7a3e8 (1-1) port 4
[ 0.119996] [00000093] libusb: debug [usbi_add_pollfd] add fd 12 events 1
[ 0.123731] [00000093] libusb: debug [usbi_io_init] using timerfd for timeouts
[ 0.126394] [00000093] libusb: debug [usbi_add_pollfd] add fd 14 events 1
2021-01-04 18:35:46.423511 <D> <event|event.c:270> Added USB event source (handle: 12, name: usb-poll, events: 0x0001) at index 2
2021-01-04 18:35:46.426421 <D> <event|event.c:270> Added USB event source (handle: 14, name: usb-poll, events: 0x0001) at index 3
2021-01-04 18:35:46.428876 <D> <usb.c:311> libusb can handle timeouts on its own
2021-01-04 18:35:46.431416 <D> <usb.c:326> libusb supports hotplug
[ 0.140552] [00000093] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 0xd7a6e0 with handle 1
[ 0.143270] [00000093] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 0xd7a7b0 with handle 2
2021-01-04 18:35:46.439536 <D> <usb.c:337> Starting initial USB device scan
2021-01-04 18:35:46.442042 <D> <usb.c:388> Looking for added/removed USB devices
[ 0.150965] [00000093] libusb: debug [libusb_get_device_list]
2021-01-04 18:35:46.448039 <D> <usb.c:111> Found 3 USB device(s)
[ 0.157060] [00000093] libusb: debug [libusb_get_device_descriptor]
[ 0.159873] [00000093] libusb: debug [libusb_get_device_descriptor]
[ 0.162587] [00000093] libusb: debug [libusb_get_device_descriptor]
2021-01-04 18:35:46.458922 <D> <network.c:177> Initializing network subsystem
2021-01-04 18:35:46.461439 <D> <socket.c:163> Opening server socket(s) for address '0.0.0.0' on port 4223
2021-01-04 18:35:46.467581 <D> <socket.c:263> Started listening to '0.0.0.0' (IPv4) resolved from '0.0.0.0' on port 4223
2021-01-04 18:35:46.470644 <D> <event|event.c:270> Added generic event source (handle: 15, name: server, events: 0x0001) at index 4
2021-01-04 18:35:46.473491 <D> <mesh.c:53> Initializing mesh subsystem
2021-01-04 18:35:46.476219 <D> <socket.c:163> Opening server socket(s) for address '0.0.0.0' on port 4240
2021-01-04 18:35:46.481557 <D> <socket.c:263> Started listening to '0.0.0.0' (IPv4) resolved from '0.0.0.0' on port 4240
2021-01-04 18:35:46.484831 <D> <event|event.c:270> Added generic event source (handle: 16, name: mesh-server, events: 0x0001) at index 5
2021-01-04 18:35:46.490397 <D> <bricklet.c:182> Found product_id "0x085d" in device tree, using pre-configured HAT Zero Brick setup
2021-01-04 18:35:46.493293 <D> <bricklet.c:220> Bricklet found: spidev /dev/spidev0.0, driver 1, name gpio27 (num 27)
2021-01-04 18:35:46.495755 <D> <bricklet_stack.c:678> Initializing Bricklet stack subsystem for '/dev/spidev0.0' (num 27)
2021-01-04 18:35:46.499201 <D> <event|event.c:270> Added generic event source (handle: 17, name: bricklet-stack-notification, events: 0x0001) at index 6
2021-01-04 18:35:46.511308 <D> <bricklet.c:220> Bricklet found: spidev /dev/spidev0.0, driver 1, name gpio23 (num 23)
2021-01-04 18:35:46.513897 <D> <bricklet_stack.c:678> Initializing Bricklet stack subsystem for '/dev/spidev0.0' (num 23)
2021-01-04 18:35:46.517475 <D> <event|event.c:270> Added generic event source (handle: 20, name: bricklet-stack-notification, events: 0x0001) at index 7
2021-01-04 18:35:46.530035 <D> <bricklet.c:220> Bricklet found: spidev /dev/spidev0.0, driver 1, name gpio24 (num 24)
2021-01-04 18:35:46.532602 <D> <bricklet_stack.c:678> Initializing Bricklet stack subsystem for '/dev/spidev0.0' (num 24)
2021-01-04 18:35:46.536281 <D> <event|event.c:270> Added generic event source (handle: 23, name: bricklet-stack-notification, events: 0x0001) at index 8
2021-01-04 18:35:46.548727 <D> <bricklet.c:220> Bricklet found: spidev /dev/spidev0.0, driver 1, name gpio22 (num 22)
2021-01-04 18:35:46.551230 <D> <bricklet_stack.c:678> Initializing Bricklet stack subsystem for '/dev/spidev0.0' (num 22)
2021-01-04 18:35:46.554820 <D> <event|event.c:270> Added generic event source (handle: 26, name: bricklet-stack-notification, events: 0x0001) at index 9
2021-01-04 18:35:46.566645 <D> <bricklet.c:220> Bricklet found: spidev /dev/spidev0.0, driver 1, name gpio25 (num 25)
2021-01-04 18:35:46.569146 <D> <bricklet_stack.c:678> Initializing Bricklet stack subsystem for '/dev/spidev0.0' (num 25)
2021-01-04 18:35:46.572683 <D> <event|event.c:270> Added generic event source (handle: 29, name: bricklet-stack-notification, events: 0x0001) at index 10
2021-01-04 18:35:46.584791 <D> <event.c:534> Starting the event loop
2021-01-04 18:35:46.587561 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-04 18:35:46.590563 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-04 18:35:46.593494 <D> <event|event.c:447> Handling USB event source (handle: 12, name: usb-poll, received-events: 0x0001)
[ 0.302540] [00000093] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.305296] [00000093] libusb: debug [handle_events] poll fds modified, reallocating
[ 0.308607] [00000093] libusb: debug [handle_events] poll() 2 fds with timeout in 0ms
[ 0.311748] [00000093] libusb: debug [handle_events] poll() returned 0
2021-01-04 18:35:46.608046 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 18:35:46.610543 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-04 18:35:47.518661 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-04 18:35:47.522010 <D> <event|event.c:447> Handling generic event source (handle: 17, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 18:35:47.526509 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.530727 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.535747 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 18:35:47.541852 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-04 18:35:47.548187 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-04 18:35:47.553169 <D> <event|event.c:447> Handling generic event source (handle: 20, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 18:35:47.559640 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.569431 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.581162 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 18:35:47.589948 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-04 18:35:47.604062 <D> <event|event_linux.c:166> EPoll returned 3 event source(s) as ready
2021-01-04 18:35:47.612385 <D> <event|event.c:447> Handling generic event source (handle: 23, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 18:35:47.624836 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.642474 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.653319 <D> <event|event.c:447> Handling generic event source (handle: 26, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 18:35:47.667059 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.683186 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.696795 <D> <event|event.c:447> Handling generic event source (handle: 29, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 18:35:47.709830 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.721984 <D> <packet|network.c:459> No clients connected, dropping callback (U: 1, L: 8, F: 252, I: 0, packet: 00 00 00 00 08 FC 08 00)
2021-01-04 18:35:47.734010 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 18:35:47.742351 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
write(2, "[111.968958] [00000093] libusb: "..., 72) = 72
close(14)                               = 0
write(11, "\1", 1)                      = 1
munmap(0xb5540000, 8392704)             = 0
close(9)                                = 0
close(10)                               = 0
close(11)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=270653131}) = 0
write(2, "2021-01-04 18:37:38.270653 <D> <"..., 87) = 87
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=273240131}) = 0
write(2, "2021-01-04 18:37:38.273240 <D> <"..., 80) = 80
rt_sigaction(SIGUSR1, {sa_handler=SIG_DFL, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=0x12144, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
rt_sigaction(SIGHUP, {sa_handler=SIG_DFL, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=0x12144, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_DFL, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
rt_sigaction(SIGTERM, {sa_handler=SIG_DFL, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=0x12144, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=0x12144, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
epoll_ctl(4, EPOLL_CTL_DEL, 7, 0xbeec9bb8) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=278570131}) = 0
write(2, "2021-01-04 18:37:38.278570 <D> <"..., 143) = 143
close(7)                                = 0
close(8)                                = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=281992131}) = 0
write(2, "2021-01-04 18:37:38.281992 <D> <"..., 75) = 75
epoll_ctl(4, EPOLL_CTL_DEL, 5, 0xbeec9b88) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=285071131}) = 0
write(2, "2021-01-04 18:37:38.285071 <D> <"..., 147) = 147
close(5)                                = 0
close(6)                                = 0
close(4)                                = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=289041131}) = 0
write(2, "2021-01-04 18:37:38.289041 <D> <"..., 156) = 156
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=291479131}) = 0
write(2, "2021-01-04 18:37:38.291479 <D> <"..., 155) = 155
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=294044131}) = 0
write(2, "2021-01-04 18:37:38.294044 <D> <"..., 155) = 155
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=296735131}) = 0
write(2, "2021-01-04 18:37:38.296735 <D> <"..., 155) = 155
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=299228131}) = 0
write(2, "2021-01-04 18:37:38.299228 <D> <"..., 155) = 155
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=301883131}) = 0
write(2, "2021-01-04 18:37:38.301883 <D> <"..., 139) = 139
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=304472131}) = 0
write(2, "2021-01-04 18:37:38.304472 <D> <"..., 134) = 134
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=306948131}) = 0
write(2, "2021-01-04 18:37:38.306948 <D> <"..., 132) = 132
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=309378131}) = 0
write(2, "2021-01-04 18:37:38.309378 <D> <"..., 132) = 132
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=311938131}) = 0
write(2, "2021-01-04 18:37:38.311938 <D> <"..., 133) = 133
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=314405131}) = 0
write(2, "2021-01-04 18:37:38.314405 <D> <"..., 137) = 137
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=316855131}) = 0
write(2, "\33[1m", 4)                   = 4
write(2, "2021-01-04 18:37:38.316855 <I> <"..., 77) = 77
write(2, "\33[m", 3)                    = 3
unlink("/var/run/brickd.pid")           = 0
close(3)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

 

 

Log bei einer Verbindung vom brickv:

Quote

2021-01-04 19:33:52.331315 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-04 19:33:52.334126 <D> <event|event.c:447> Handling generic event source (handle: 15, name: server, received-events: 0x0001)
2021-01-04 19:33:52.344060 <D> <client.c:382> Creating client from plain-socket (handle: 32/32)
2021-01-04 19:33:52.356264 <D> <event|event.c:270> Added generic event source (handle: 32, name: client, events: 0x0001) at index 11
2021-01-04 19:33:52.365129 <I> <network.c:304> Added new client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 0, P: 0, A: disabled)
2021-01-04 19:33:52.382132 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 19:33:52.390782 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-04 19:33:52.403394 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-04 19:33:52.412624 <D> <event|event.c:447> Handling generic event source (handle: 32, name: client, received-events: 0x0001)
2021-01-04 19:33:52.430941 <D> <packet|client.c:324> Received request (U: 1, L: 8, F: 254, S: 15, R: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) from client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 8, P: 0, A: disabled)
2021-01-04 19:33:52.439751 <D> <packet|hardware.c:115> Broadcasting request (U: 1, L: 8, F: 254, S: 15, R: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) to 5 stack(s)
2021-01-04 19:33:52.448891 <D> <packet|bricklet_stack.c:87> Packet is queued to be send over SPI (U: 1, L: 8, F: 254, S: 15, R: 0, I: 0, packet: 00 00 00 00 08 FE F0 00)
2021-01-04 19:33:52.456227 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-04 19:33:52.464932 <D> <packet|bricklet_stack.c:87> Packet is queued to be send over SPI (U: 1, L: 8, F: 254, S: 15, R: 0, I: 0, packet: 00 00 00 00 08 FE F0 00)
2021-01-04 19:33:52.474887 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-04 19:33:52.483565 <D> <packet|bricklet_stack.c:87> Packet is queued to be send over SPI (U: 1, L: 8, F: 254, S: 15, R: 0, I: 0, packet: 00 00 00 00 08 FE F0 00)
2021-01-04 19:33:52.492198 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-04 19:33:52.499175 <D> <packet|bricklet_stack.c:87> Packet is queued to be send over SPI (U: 1, L: 8, F: 254, S: 15, R: 0, I: 0, packet: 00 00 00 00 08 FE F0 00)
2021-01-04 19:33:52.509152 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-04 19:33:52.518143 <D> <packet|bricklet_stack.c:87> Packet is queued to be send over SPI (U: 1, L: 8, F: 254, S: 15, R: 0, I: 0, packet: 00 00 00 00 08 FE F0 00)
2021-01-04 19:33:52.527359 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-04 19:33:52.536627 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 19:33:52.544380 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-04 19:33:52.556925 <D> <event|event_linux.c:166> EPoll returned 5 event source(s) as ready
2021-01-04 19:33:52.566100 <D> <event|event.c:447> Handling generic event source (handle: 17, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 19:33:52.577231 <D> <packet|network.c:479> Dispatching response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) to 1 client(s) and 0 zombies(s)
2021-01-04 19:33:52.585882 <W> <network.c:505> Broadcasting response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) because no client/zombie has a matching pending request
2021-01-04 19:33:52.609634 <D> <packet|client.c:508> Forced to send response to client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 0, P: 0, A: disabled)
2021-01-04 19:33:52.621010 <D> <event|event.c:447> Handling generic event source (handle: 20, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 19:33:52.633556 <D> <packet|network.c:479> Dispatching response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) to 1 client(s) and 0 zombies(s)
2021-01-04 19:33:52.641949 <W> <network.c:505> Broadcasting response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) because no client/zombie has a matching pending request
2021-01-04 19:33:52.664755 <D> <packet|client.c:508> Forced to send response to client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 0, P: 0, A: disabled)
2021-01-04 19:33:52.675893 <D> <event|event.c:447> Handling generic event source (handle: 23, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 19:33:52.688330 <D> <packet|network.c:479> Dispatching response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) to 1 client(s) and 0 zombies(s)
2021-01-04 19:33:52.696493 <W> <network.c:505> Broadcasting response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) because no client/zombie has a matching pending request
2021-01-04 19:33:52.719929 <D> <packet|client.c:508> Forced to send response to client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 0, P: 0, A: disabled)
2021-01-04 19:33:52.731624 <D> <event|event.c:447> Handling generic event source (handle: 26, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 19:33:52.743242 <D> <packet|network.c:479> Dispatching response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) to 1 client(s) and 0 zombies(s)
2021-01-04 19:33:52.751257 <W> <network.c:505> Broadcasting response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) because no client/zombie has a matching pending request
2021-01-04 19:33:52.774046 <D> <packet|client.c:508> Forced to send response to client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 0, P: 0, A: disabled)
2021-01-04 19:33:52.785667 <D> <event|event.c:447> Handling generic event source (handle: 29, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-04 19:33:52.797198 <D> <packet|network.c:479> Dispatching response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) to 1 client(s) and 0 zombies(s)
2021-01-04 19:33:52.806240 <W> <network.c:505> Broadcasting response (U: 1, L: 8, F: 254, S: 15, E: 0, I: 0, packet: 00 00 00 00 08 FE F0 00) because no client/zombie has a matching pending request
2021-01-04 19:33:52.829510 <D> <packet|client.c:508> Forced to send response to client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 0, P: 0, A: disabled)
2021-01-04 19:33:52.841461 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 19:33:52.850232 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-04 19:34:02.332038 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-04 19:34:02.334668 <D> <event|event.c:447> Handling generic event source (handle: 32, name: client, received-events: 0x0001)
2021-01-04 19:34:02.337873 <D> <packet|client.c:314> Received disconnect probe from client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 8, P: 0, A: disabled), dropping request
2021-01-04 19:34:02.346011 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 19:34:02.354740 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-04 19:34:07.335771 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-04 19:34:07.338823 <D> <event|event.c:447> Handling generic event source (handle: 32, name: client, received-events: 0x0001)
2021-01-04 19:34:07.341997 <D> <packet|client.c:314> Received disconnect probe from client (N: 192.168.77.4:39310, T: plain-socket, H: 32/32, B: 8, P: 0, A: disabled), dropping request
2021-01-04 19:34:07.347204 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-04 19:34:07.356229 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)

 

 

strace:

Quote

execve("./brickd-2.4.1", ["./brickd-2.4.1", "--debug"], 0xbeffbd9c /* 14 vars */) = 0
brk(NULL)                               = 0xd79000
uname({sysname="Linux", nodename="rpizero", ...}) = 0
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/tls/v6l/vfp/librt.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/v6l/vfp", 0xbeec91d0)  = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/tls/v6l/librt.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/v6l", 0xbeec91d0)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/tls/vfp/librt.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/vfp", 0xbeec91d0)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/tls/librt.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls", 0xbeec91d0)          = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/v6l/vfp/librt.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/v6l/vfp", 0xbeec91d0)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/v6l/librt.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/v6l", 0xbeec91d0)          = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/vfp/librt.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/vfp", 0xbeec91d0)          = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/lib/librt.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\340\25\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=26408, ...}) = 0
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f5c000
mmap2(NULL, 90624, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6f16000
mprotect(0xb6f1c000, 61440, PROT_NONE)  = 0
mmap2(0xb6f2b000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x5000) = 0xb6f2b000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/tls/v6l/vfp/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/v6l/vfp", 0xbeec91c0) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/tls/v6l/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/v6l", 0xbeec91c0)  = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/tls/vfp/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/vfp", 0xbeec91c0)  = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/tls/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls", 0xbeec91c0)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/v6l/vfp/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/v6l/vfp", 0xbeec91c0)  = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/v6l/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/v6l", 0xbeec91c0)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/vfp/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/vfp", 0xbeec91c0)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/libusb-1.0.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\250.\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=83660, ...}) = 0
mmap2(NULL, 148144, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6ef1000
mprotect(0xb6f04000, 65536, PROT_NONE)  = 0
mmap2(0xb6f14000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13000) = 0xb6f14000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libdl.so.2", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\210\t\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=9596, ...}) = 0
mmap2(NULL, 73916, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6ede000
mprotect(0xb6ee0000, 61440, PROT_NONE)  = 0
mmap2(0xb6eef000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1000) = 0xb6eef000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libgcc_s.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0P\364\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=124392, ...}) = 0
mmap2(NULL, 188724, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6eaf000
mprotect(0xb6ecd000, 61440, PROT_NONE)  = 0
mmap2(0xb6edc000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1d000) = 0xb6edc000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libpthread.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\270L\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=129212, ...}) = 0
mmap2(NULL, 168528, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6e85000
mprotect(0xb6e9c000, 61440, PROT_NONE)  = 0
mmap2(0xb6eab000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0xb6eab000
mmap2(0xb6ead000, 4688, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb6ead000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libc.so.6", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\200x\1\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1245892, ...}) = 0
mmap2(NULL, 1315392, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6d43000
mprotect(0xb6e6f000, 65536, PROT_NONE)  = 0
mmap2(0xb6e7f000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x12c000) = 0xb6e7f000
mmap2(0xb6e82000, 8768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb6e82000
close(3)                                = 0
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f5a000
set_tls(0xb6f5a4d0)                     = 0
mprotect(0xb6e7f000, 8192, PROT_READ)   = 0
mprotect(0xb6eab000, 4096, PROT_READ)   = 0
mprotect(0xb6edc000, 4096, PROT_READ)   = 0
mprotect(0xb6eef000, 4096, PROT_READ)   = 0
mprotect(0xb6f14000, 4096, PROT_READ)   = 0
mprotect(0xb6f2b000, 4096, PROT_READ)   = 0
mprotect(0xb6f5e000, 4096, PROT_READ)   = 0
set_tid_address(0xb6f5a078)             = 147
set_robust_list(0xb6f5a080, 12)         = 0
rt_sigaction(SIGRTMIN, {sa_handler=0xb6e89680, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0xb6d71020}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {sa_handler=0xb6e8973c, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO, sa_restorer=0xb6d71020}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
ugetrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0
getuid32()                              = 0
brk(NULL)                               = 0xd79000
brk(0xd9a000)                           = 0xd9a000
openat(AT_FDCWD, "/etc/brickd.conf", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=3783, ...}) = 0
read(3, "# Brick Daemon Configuration\n#\n#"..., 1024) = 1024
read(3, "wser can freely connect to your "..., 1024) = 1024
read(3, "entication is disabled. If the s"..., 1024) = 1024
read(3, "tatements (FIXME: Add\n# more det"..., 1024) = 711
read(3, "", 1024)                       = 0
close(3)                                = 0
ioctl(2, TCGETS, {B38400 opost isig icanon echo ...}) = 0
getpid()                                = 147
openat(AT_FDCWD, "/var/run/brickd.pid", O_WRONLY|O_CREAT, 0644) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fcntl64(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=0, l_len=1}) = 0
stat64("/var/run/brickd.pid", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
write(3, "147", 3)                      = 3
getpid()                                = 147
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=260210131}) = 0
openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
write(2, "\33[1m", 4)                   = 4
write(2, "2021-01-04 18:35:46.260210 <I> <"..., 103) = 103
write(2, "\33[m", 3)                    = 3
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=266504131}) = 0
write(2, "2021-01-04 18:35:46.266504 <D> <"..., 86) = 86
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=269294131}) = 0
write(2, "2021-01-04 18:35:46.269294 <D> <"..., 86) = 86
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=272048131}) = 0
write(2, "2021-01-04 18:35:46.272048 <D> <"..., 73) = 73
epoll_create1(EPOLL_CLOEXEC)            = 4
pipe([5, 6])                            = 0
epoll_ctl(4, EPOLL_CTL_ADD, 5, {EPOLLIN, {u32=14132776, u64=14132776}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=275942131}) = 0
write(2, "2021-01-04 18:35:46.275942 <D> <"..., 135) = 135
pipe([7, 8])                            = 0
epoll_ctl(4, EPOLL_CTL_ADD, 7, {EPOLLIN, {u32=14132904, u64=14132904}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=279570131}) = 0
write(2, "2021-01-04 18:35:46.279570 <D> <"..., 131) = 131
rt_sigaction(SIGINT, {sa_handler=0x12144, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTERM, {sa_handler=0x12144, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGHUP, {sa_handler=0x12144, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR1, {sa_handler=0x12144, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=284587131}) = 0
write(2, "2021-01-04 18:35:46.284587 <D> <"..., 79) = 79
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=287548131}) = 0
write(2, "2021-01-04 18:35:46.287548 <D> <"..., 70) = 70
futex(0xb6ef00b0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=290649131}) = 0
write(2, "2021-01-04 18:35:46.290649 <D> <"..., 97) = 97
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=293561131}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=294078131}) = 0
write(2, "[timestamp] [threadID] facility "..., 64) = 64
write(2, "--------------------------------"..., 81) = 81
gettid()                                = 147
write(2, "[ 0.000517] [00000093] libusb: d"..., 75) = 75
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=300827131}) = 0
gettid()                                = 147
write(2, "[ 0.007266] [00000093] libusb: d"..., 72) = 72
openat(AT_FDCWD, "/dev/bus/usb", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_CLOEXEC|O_DIRECTORY) = 9
fstat64(9, {st_mode=S_IFDIR|0755, st_size=60, ...}) = 0
getdents64(9, 0xd7b190 /* 3 entries */, 32768) = 72
close(9)                                = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=306036131}) = 0
gettid()                                = 147
write(2, "[ 0.012475] [00000093] libusb: d"..., 83) = 83
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=79, tv_nsec=77138131}) = 0
uname({sysname="Linux", nodename="rpizero", ...}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=309745131}) = 0
gettid()                                = 147
write(2, "[ 0.016184] [00000093] libusb: d"..., 92) = 92
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=312521131}) = 0
gettid()                                = 147
write(2, "[ 0.018960] [00000093] libusb: d"..., 80) = 80
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=315537131}) = 0
gettid()                                = 147
write(2, "[ 0.021976] [00000093] libusb: d"..., 81) = 81
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=318227131}) = 0
gettid()                                = 147
write(2, "[ 0.024666] [00000093] libusb: d"..., 93) = 93
stat64("/sys/bus/usb/devices", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=321840131}) = 0
gettid()                                = 147
write(2, "[ 0.028279] [00000093] libusb: d"..., 72) = 72
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=324722131}) = 0
gettid()                                = 147
write(2, "[ 0.031161] [00000093] libusb: d"..., 78) = 78
socket(AF_NETLINK, SOCK_RAW|SOCK_CLOEXEC|SOCK_NONBLOCK, NETLINK_KOBJECT_UEVENT) = 9
bind(9, {sa_family=AF_NETLINK, nl_pid=0, nl_groups=0x000001}, 12) = 0
setsockopt(9, SOL_SOCKET, SO_PASSCRED, [1], 4) = 0
pipe2([10, 11], O_CLOEXEC)              = 0
fcntl64(11, F_GETFL)                    = 0x1 (flags O_WRONLY)
fcntl64(11, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
mmap2(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0xb6542000
mprotect(0xb6543000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0xb6d41f98, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tid=[148], tls=0xb6d42920, child_tidptr=0xb6d424c8) = 148
openat(AT_FDCWD, "/sys/bus/usb/devices", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_CLOEXEC|O_DIRECTORY) = 12
fstat64(12, {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
getdents64(12, 0xd7b190 /* 8 entries */, 32768) = 224
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=333417131}) = 0
gettid()                                = 147
write(2, "[ 0.039856] [00000093] libusb: d"..., 109) = 109
futex(0xb6e8264c, FUTEX_WAKE_PRIVATE, 1) = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=338349131}) = 0
gettid()                                = 147
write(2, "[ 0.044788] [00000093] libusb: d"..., 74) = 74
openat(AT_FDCWD, "/sys/bus/usb/devices/usb1/busnum", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "1\n", 4096)                   = 2
close(13)                               = 0
openat(AT_FDCWD, "/sys/bus/usb/devices/usb1/devnum", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "1\n", 4096)                   = 2
close(13)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=346551131}) = 0
gettid()                                = 147
write(2, "[ 0.052990] [00000093] libusb: d"..., 76) = 76
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=349280131}) = 0
gettid()                                = 147
write(2, "[ 0.055719] [00000093] libusb: d"..., 96) = 96
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=352061131}) = 0
gettid()                                = 147
write(2, "[ 0.058500] [00000093] libusb: d"..., 106) = 106
openat(AT_FDCWD, "/sys/bus/usb/devices/usb1/speed", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "480\n", 4096)                 = 4
close(13)                               = 0
openat(AT_FDCWD, "/sys/bus/usb/devices/usb1/descriptors", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
read(13, "\22\1\0\2\t\0\1@k\35\2\0\4\5\3\2\1\1\t\2\31\0\1\1\0\340\0\t\4\0\0\1"..., 1024) = 43
close(13)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=359148131}) = 0
gettid()                                = 147
write(2, "[ 0.065587] [00000093] libusb: d"..., 108) = 108
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=362015131}) = 0
gettid()                                = 147
write(2, "[ 0.068454] [00000093] libusb: d"..., 73) = 73
openat(AT_FDCWD, "/sys/bus/usb/devices/1-1/busnum", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "1\n", 4096)                   = 2
close(13)                               = 0
openat(AT_FDCWD, "/sys/bus/usb/devices/1-1/devnum", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "2\n", 4096)                   = 2
close(13)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=369536131}) = 0
gettid()                                = 147
write(2, "[ 0.075975] [00000093] libusb: d"..., 76) = 76
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=372324131}) = 0
gettid()                                = 147
write(2, "[ 0.078763] [00000093] libusb: d"..., 96) = 96
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=375058131}) = 0
gettid()                                = 147
write(2, "[ 0.081497] [00000093] libusb: d"..., 106) = 106
openat(AT_FDCWD, "/sys/bus/usb/devices/1-1/speed", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "480\n", 4096)                 = 4
close(13)                               = 0
openat(AT_FDCWD, "/sys/bus/usb/devices/1-1/descriptors", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
read(13, "\22\1\0\2\t\0\1@@\32\1\1\21\1\0\1\0\1\t\2\31\0\1\1\0\3402\t\4\0\0\1"..., 1024) = 43
close(13)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=382191131}) = 0
gettid()                                = 147
write(2, "[ 0.088630] [00000093] libusb: d"..., 114) = 114
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=384949131}) = 0
gettid()                                = 147
write(2, "[ 0.091388] [00000093] libusb: d"..., 110) = 110
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=387672131}) = 0
gettid()                                = 147
write(2, "[ 0.094111] [00000093] libusb: d"..., 75) = 75
openat(AT_FDCWD, "/sys/bus/usb/devices/1-1.4/busnum", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "1\n", 4096)                   = 2
close(13)                               = 0
openat(AT_FDCWD, "/sys/bus/usb/devices/1-1.4/devnum", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "3\n", 4096)                   = 2
close(13)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=395516131}) = 0
gettid()                                = 147
write(2, "[ 0.101955] [00000093] libusb: d"..., 76) = 76
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=398541131}) = 0
gettid()                                = 147
write(2, "[ 0.104980] [00000093] libusb: d"..., 96) = 96
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=401276131}) = 0
gettid()                                = 147
write(2, "[ 0.107715] [00000093] libusb: d"..., 106) = 106
openat(AT_FDCWD, "/sys/bus/usb/devices/1-1.4/speed", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
fcntl64(13, F_GETFL)                    = 0x20000 (flags O_RDONLY|O_LARGEFILE)
fstat64(13, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
read(13, "480\n", 4096)                 = 4
close(13)                               = 0
openat(AT_FDCWD, "/sys/bus/usb/devices/1-1.4/descriptors", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 13
read(13, "\22\1\20\2\0\0\0@\332\vR\201\0 \1\2\3\2\t\2'\0\1\1\0\2402\t\4\0\0\3"..., 1024) = 137
close(13)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=408203131}) = 0
gettid()                                = 147
write(2, "[ 0.114642] [00000093] libusb: d"..., 115) = 115
getdents64(12, 0xd7b190 /* 0 entries */, 32768) = 0
close(12)                               = 0
pipe2([12, 13], O_CLOEXEC)              = 0
fcntl64(13, F_GETFL)                    = 0x1 (flags O_WRONLY)
fcntl64(13, F_SETFL, O_WRONLY|O_NONBLOCK) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=413557131}) = 0
gettid()                                = 147
write(2, "[ 0.119996] [00000093] libusb: d"..., 74) = 74
write(13, "\1", 1)                      = 1
timerfd_create(CLOCK_MONOTONIC, TFD_CLOEXEC|TFD_NONBLOCK) = 14
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=417292131}) = 0
gettid()                                = 147
write(2, "[ 0.123731] [00000093] libusb: d"..., 79) = 79
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=419955131}) = 0
gettid()                                = 147
write(2, "[ 0.126394] [00000093] libusb: d"..., 74) = 74
epoll_ctl(4, EPOLL_CTL_ADD, 12, {EPOLLIN, {u32=14131800, u64=14131800}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=423511131}) = 0
write(2, "2021-01-04 18:35:46.423511 <D> <"..., 130) = 130
epoll_ctl(4, EPOLL_CTL_ADD, 14, {EPOLLIN, {u32=14131856, u64=14131856}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=426421131}) = 0
write(2, "2021-01-04 18:35:46.426421 <D> <"..., 130) = 130
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=428876131}) = 0
write(2, "2021-01-04 18:35:46.428876 <D> <"..., 81) = 81
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=431416131}) = 0
write(2, "2021-01-04 18:35:46.431416 <D> <"..., 67) = 67
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=434113131}) = 0
gettid()                                = 147
write(2, "[ 0.140552] [00000093] libusb: d"..., 110) = 110
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=436831131}) = 0
gettid()                                = 147
write(2, "[ 0.143270] [00000093] libusb: d"..., 110) = 110
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=439536131}) = 0
write(2, "2021-01-04 18:35:46.439536 <D> <"..., 76) = 76
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=442042131}) = 0
write(2, "2021-01-04 18:35:46.442042 <D> <"..., 81) = 81
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=444526131}) = 0
gettid()                                = 147
write(2, "[ 0.150965] [00000093] libusb: d"..., 63) = 63
recvmsg(9, {msg_namelen=12}, 0)         = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=448039131}) = 0
write(2, "2021-01-04 18:35:46.448039 <D> <"..., 65) = 65
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=450621131}) = 0
gettid()                                = 147
write(2, "[ 0.157060] [00000093] libusb: d"..., 69) = 69
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=453434131}) = 0
gettid()                                = 147
write(2, "[ 0.159873] [00000093] libusb: d"..., 69) = 69
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=456148131}) = 0
gettid()                                = 147
write(2, "[ 0.162587] [00000093] libusb: d"..., 69) = 69
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=458922131}) = 0
write(2, "2021-01-04 18:35:46.458922 <D> <"..., 78) = 78
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=461439131}) = 0
write(2, "2021-01-04 18:35:46.461439 <D> <"..., 106) = 106
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 15
setsockopt(15, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
bind(15, {sa_family=AF_INET, sin_port=htons(4223), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
setsockopt(15, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl64(15, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(15, F_SETFL, O_RDWR|O_NONBLOCK) = 0
listen(15, 10)                          = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=467581131}) = 0
write(2, "2021-01-04 18:35:46.467581 <D> <"..., 121) = 121
epoll_ctl(4, EPOLL_CTL_ADD, 15, {EPOLLIN, {u32=14129216, u64=14129216}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=470644131}) = 0
write(2, "2021-01-04 18:35:46.470644 <D> <"..., 132) = 132
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=473491131}) = 0
write(2, "2021-01-04 18:35:46.473491 <D> <"..., 71) = 71
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=476219131}) = 0
write(2, "2021-01-04 18:35:46.476219 <D> <"..., 106) = 106
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 16
setsockopt(16, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
bind(16, {sa_family=AF_INET, sin_port=htons(4240), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
setsockopt(16, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl64(16, F_GETFL)                    = 0x2 (flags O_RDWR)
fcntl64(16, F_SETFL, O_RDWR|O_NONBLOCK) = 0
listen(16, 10)                          = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=481557131}) = 0
write(2, "2021-01-04 18:35:46.481557 <D> <"..., 121) = 121
epoll_ctl(4, EPOLL_CTL_ADD, 16, {EPOLLIN, {u32=14135104, u64=14135104}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=484831131}) = 0
write(2, "2021-01-04 18:35:46.484831 <D> <"..., 137) = 137
openat(AT_FDCWD, "/proc/device-tree/hat/product_id", O_RDONLY) = 17
read(17, "0x085d", 6)                   = 6
close(17)                               = 0
openat(AT_FDCWD, "/proc/device-tree/hat/product_id", O_RDONLY) = 17
read(17, "0x085d", 6)                   = 6
close(17)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=490397131}) = 0
write(2, "2021-01-04 18:35:46.490397 <D> <"..., 132) = 132
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=493293131}) = 0
write(2, "2021-01-04 18:35:46.493293 <D> <"..., 118) = 118
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=495755131}) = 0
write(2, "2021-01-04 18:35:46.495755 <D> <"..., 122) = 122
eventfd2(0, EFD_SEMAPHORE|EFD_NONBLOCK) = 17
epoll_ctl(4, EPOLL_CTL_ADD, 17, {EPOLLIN, {u32=14129344, u64=14129344}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=499201131}) = 0
write(2, "2021-01-04 18:35:46.499201 <D> <"..., 153) = 153
openat(AT_FDCWD, "/sys/class/gpio/export", O_WRONLY) = 18
write(18, "27", 2)                      = 2
close(18)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio27/direction", O_WRONLY) = 18
write(18, "out", 3)                     = 3
close(18)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio27/value", O_WRONLY) = 18
write(18, "1", 1)                       = 1
close(18)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio27/value", O_WRONLY) = 18
openat(AT_FDCWD, "/dev/spidev0.0", O_RDWR) = 19
ioctl(19, SPI_IOC_WR_MODE, 0xbeec98d8)  = 0
ioctl(19, SPI_IOC_WR_MAX_SPEED_HZ, 0xbeec98e4) = 0
ioctl(19, SPI_IOC_WR_BITS_PER_WORD, 0xbeec98e0) = 0
ioctl(19, SPI_IOC_WR_LSB_FIRST, 0xbeec98dc) = 0
mmap2(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0xb5d41000
mprotect(0xb5d42000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0xb6540f98, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tid=[149], tls=0xb6541920, child_tidptr=0xb65414c8) = 149
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=511308131}) = 0
write(2, "2021-01-04 18:35:46.511308 <D> <"..., 118) = 118
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=513897131}) = 0
write(2, "2021-01-04 18:35:46.513897 <D> <"..., 122) = 122
eventfd2(0, EFD_SEMAPHORE|EFD_NONBLOCK) = 20
epoll_ctl(4, EPOLL_CTL_ADD, 20, {EPOLLIN, {u32=14129400, u64=14129400}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=517475131}) = 0
write(2, "2021-01-04 18:35:46.517475 <D> <"..., 153) = 153
openat(AT_FDCWD, "/sys/class/gpio/export", O_WRONLY) = 21
write(21, "23", 2)                      = 2
close(21)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio23/direction", O_WRONLY) = 21
write(21, "out", 3)                     = 3
close(21)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio23/value", O_WRONLY) = 21
write(21, "1", 1)                       = 1
close(21)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio23/value", O_WRONLY) = 21
openat(AT_FDCWD, "/dev/spidev0.0", O_RDWR) = 22
ioctl(22, SPI_IOC_WR_MODE, 0xbeec98d8)  = 0
ioctl(22, SPI_IOC_WR_MAX_SPEED_HZ, 0xbeec98e4) = 0
ioctl(22, SPI_IOC_WR_BITS_PER_WORD, 0xbeec98e0) = 0
ioctl(22, SPI_IOC_WR_LSB_FIRST, 0xbeec98dc) = 0
mmap2(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0xb5540000
mprotect(0xb5541000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0xb5d3ff98, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tid=[150], tls=0xb5d40920, child_tidptr=0xb5d404c8) = 150
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=530035131}) = 0
write(2, "2021-01-04 18:35:46.530035 <D> <"..., 118) = 118
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=532602131}) = 0
write(2, "2021-01-04 18:35:46.532602 <D> <"..., 122) = 122
eventfd2(0, EFD_SEMAPHORE|EFD_NONBLOCK) = 23
epoll_ctl(4, EPOLL_CTL_ADD, 23, {EPOLLIN, {u32=14129456, u64=14129456}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=536281131}) = 0
write(2, "2021-01-04 18:35:46.536281 <D> <"..., 153) = 153
openat(AT_FDCWD, "/sys/class/gpio/export", O_WRONLY) = 24
write(24, "24", 2)                      = 2
close(24)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio24/direction", O_WRONLY) = 24
write(24, "out", 3)                     = 3
close(24)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio24/value", O_WRONLY) = 24
write(24, "1", 1)                       = 1
close(24)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio24/value", O_WRONLY) = 24
openat(AT_FDCWD, "/dev/spidev0.0", O_RDWR) = 25
ioctl(25, SPI_IOC_WR_MODE, 0xbeec98d8)  = 0
ioctl(25, SPI_IOC_WR_MAX_SPEED_HZ, 0xbeec98e4) = 0
ioctl(25, SPI_IOC_WR_BITS_PER_WORD, 0xbeec98e0) = 0
ioctl(25, SPI_IOC_WR_LSB_FIRST, 0xbeec98dc) = 0
mmap2(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0xb4d3f000
mprotect(0xb4d40000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0xb553ef98, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tid=[151], tls=0xb553f920, child_tidptr=0xb553f4c8) = 151
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=548727131}) = 0
write(2, "2021-01-04 18:35:46.548727 <D> <"..., 118) = 118
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=551230131}) = 0
write(2, "2021-01-04 18:35:46.551230 <D> <"..., 122) = 122
eventfd2(0, EFD_SEMAPHORE|EFD_NONBLOCK) = 26
epoll_ctl(4, EPOLL_CTL_ADD, 26, {EPOLLIN, {u32=14135592, u64=14135592}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=554820131}) = 0
write(2, "2021-01-04 18:35:46.554820 <D> <"..., 153) = 153
openat(AT_FDCWD, "/sys/class/gpio/export", O_WRONLY) = 27
write(27, "22", 2)                      = 2
close(27)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio22/direction", O_WRONLY) = 27
write(27, "out", 3)                     = 3
close(27)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio22/value", O_WRONLY) = 27
write(27, "1", 1)                       = 1
close(27)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio22/value", O_WRONLY) = 27
openat(AT_FDCWD, "/dev/spidev0.0", O_RDWR) = 28
ioctl(28, SPI_IOC_WR_MODE, 0xbeec98d8)  = 0
ioctl(28, SPI_IOC_WR_MAX_SPEED_HZ, 0xbeec98e4) = 0
ioctl(28, SPI_IOC_WR_BITS_PER_WORD, 0xbeec98e0) = 0
ioctl(28, SPI_IOC_WR_LSB_FIRST, 0xbeec98dc) = 0
mmap2(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0xb453e000
mprotect(0xb453f000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0xb4d3df98, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tid=[152], tls=0xb4d3e920, child_tidptr=0xb4d3e4c8) = 152
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=566645131}) = 0
write(2, "2021-01-04 18:35:46.566645 <D> <"..., 118) = 118
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=569146131}) = 0
write(2, "2021-01-04 18:35:46.569146 <D> <"..., 122) = 122
eventfd2(0, EFD_SEMAPHORE|EFD_NONBLOCK) = 29
epoll_ctl(4, EPOLL_CTL_ADD, 29, {EPOLLIN, {u32=14138408, u64=14138408}}) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=572683131}) = 0
write(2, "2021-01-04 18:35:46.572683 <D> <"..., 154) = 154
openat(AT_FDCWD, "/sys/class/gpio/export", O_WRONLY) = 30
write(30, "25", 2)                      = 2
close(30)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio25/direction", O_WRONLY) = 30
write(30, "out", 3)                     = 3
close(30)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio25/value", O_WRONLY) = 30
write(30, "1", 1)                       = 1
close(30)                               = 0
openat(AT_FDCWD, "/sys/class/gpio/gpio25/value", O_WRONLY) = 30
openat(AT_FDCWD, "/dev/spidev0.0", O_RDWR) = 31
ioctl(31, SPI_IOC_WR_MODE, 0xbeec98d8)  = 0
ioctl(31, SPI_IOC_WR_MAX_SPEED_HZ, 0xbeec98e4) = 0
ioctl(31, SPI_IOC_WR_BITS_PER_WORD, 0xbeec98e0) = 0
ioctl(31, SPI_IOC_WR_LSB_FIRST, 0xbeec98dc) = 0
mmap2(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0xb3d3d000
mprotect(0xb3d3e000, 8388608, PROT_READ|PROT_WRITE) = 0
clone(child_stack=0xb453cf98, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tid=[153], tls=0xb453d920, child_tidptr=0xb453d4c8) = 153
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=584791131}) = 0
write(2, "2021-01-04 18:35:46.584791 <D> <"..., 69) = 69
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=587561131}) = 0
write(2, "2021-01-04 18:35:46.587561 <D> <"..., 97) = 97
epoll_wait(4, [{EPOLLIN, {u32=14131800, u64=14131800}}], 11, -1) = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=590563131}) = 0
write(2, "2021-01-04 18:35:46.590563 <D> <"..., 99) = 99
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=593494131}) = 0
write(2, "2021-01-04 18:35:46.593494 <D> <"..., 131) = 131
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=596101131}) = 0
gettid()                                = 147
write(2, "[ 0.302540] [00000093] libusb: d"..., 107) = 107
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=598857131}) = 0
gettid()                                = 147
write(2, "[ 0.305296] [00000093] libusb: d"..., 85) = 85
read(12, "\1", 1)                       = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=602168131}) = 0
gettid()                                = 147
write(2, "[ 0.308607] [00000093] libusb: d"..., 86) = 86
poll([{fd=12, events=POLLIN}, {fd=14, events=POLLIN}], 2, 0) = 0 (Timeout)
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=605309131}) = 0
gettid()                                = 147
write(2, "[ 0.311748] [00000093] libusb: d"..., 71) = 71
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=608046131}) = 0
write(2, "2021-01-04 18:35:46.608046 <D> <"..., 89) = 89
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785346, tv_nsec=610543131}) = 0
write(2, "2021-01-04 18:35:46.610543 <D> <"..., 97) = 97
epoll_wait(4, [{EPOLLIN, {u32=14129344, u64=14129344}}], 11, -1) = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=518661131}) = 0
write(2, "2021-01-04 18:35:47.518661 <D> <"..., 99) = 99
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=522010131}) = 0
write(2, "2021-01-04 18:35:47.522010 <D> <"..., 154) = 154
read(17, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=526509131}) = 0
write(2, "2021-01-04 18:35:47.526509 <D> <"..., 154) = 154
read(17, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=530727131}) = 0
write(2, "2021-01-04 18:35:47.530727 <D> <"..., 154) = 154
read(17, 0xbeec9b40, 8)                 = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=535747131}) = 0
write(2, "2021-01-04 18:35:47.535747 <D> <"..., 89) = 89
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=541852131}) = 0
write(2, "2021-01-04 18:35:47.541852 <D> <"..., 97) = 97
epoll_wait(4, [{EPOLLIN, {u32=14129400, u64=14129400}}], 11, -1) = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=548187131}) = 0
write(2, "2021-01-04 18:35:47.548187 <D> <"..., 99) = 99
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=553169131}) = 0
write(2, "2021-01-04 18:35:47.553169 <D> <"..., 154) = 154
read(20, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=559640131}) = 0
write(2, "2021-01-04 18:35:47.559640 <D> <"..., 154) = 154
read(20, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=569431131}) = 0
write(2, "2021-01-04 18:35:47.569431 <D> <"..., 154) = 154
read(20, 0xbeec9b40, 8)                 = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=581162131}) = 0
write(2, "2021-01-04 18:35:47.581162 <D> <"..., 89) = 89
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=589948131}) = 0
write(2, "2021-01-04 18:35:47.589948 <D> <"..., 97) = 97
epoll_wait(4, [{EPOLLIN, {u32=14129456, u64=14129456}}, {EPOLLIN, {u32=14135592, u64=14135592}}, {EPOLLIN, {u32=14138408, u64=14138408}}], 11, -1) = 3
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=604062131}) = 0
write(2, "2021-01-04 18:35:47.604062 <D> <"..., 99) = 99
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=612385131}) = 0
write(2, "2021-01-04 18:35:47.612385 <D> <"..., 154) = 154
read(23, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=624836131}) = 0
write(2, "2021-01-04 18:35:47.624836 <D> <"..., 154) = 154
read(23, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=642474131}) = 0
write(2, "2021-01-04 18:35:47.642474 <D> <"..., 154) = 154
read(23, 0xbeec9b40, 8)                 = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=653319131}) = 0
write(2, "2021-01-04 18:35:47.653319 <D> <"..., 154) = 154
read(26, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=667059131}) = 0
write(2, "2021-01-04 18:35:47.667059 <D> <"..., 154) = 154
read(26, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=683186131}) = 0
write(2, "2021-01-04 18:35:47.683186 <D> <"..., 154) = 154
read(26, 0xbeec9b40, 8)                 = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=696795131}) = 0
write(2, "2021-01-04 18:35:47.696795 <D> <"..., 154) = 154
read(29, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=709830131}) = 0
write(2, "2021-01-04 18:35:47.709830 <D> <"..., 154) = 154
read(29, "\1\0\0\0\0\0\0\0", 8)         = 8
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=721984131}) = 0
write(2, "2021-01-04 18:35:47.721984 <D> <"..., 154) = 154
read(29, 0xbeec9b40, 8)                 = -1 EAGAIN (Resource temporarily unavailable)
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=734010131}) = 0
write(2, "2021-01-04 18:35:47.734010 <D> <"..., 89) = 89
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785347, tv_nsec=742351131}) = 0
write(2, "2021-01-04 18:35:47.742351 <D> <"..., 97) = 97
epoll_wait(4, 0xd7bcf0, 11, -1)         = -1 EINTR (Interrupted system call)
--- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
write(8, "\2\0\0\0", 4)                 = 4
sigreturn({mask=[]})                    = -1 EINTR (Interrupted system call)
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=48841131}) = 0
write(2, "2021-01-04 18:37:38.048841 <D> <"..., 73) = 73
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=51933131}) = 0
write(2, "2021-01-04 18:37:38.051933 <D> <"..., 97) = 97
epoll_wait(4, [{EPOLLIN, {u32=14132904, u64=14132904}}], 11, -1) = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=62069131}) = 0
write(2, "2021-01-04 18:37:38.062069 <D> <"..., 99) = 99
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=71786131}) = 0
write(2, "2021-01-04 18:37:38.071786 <D> <"..., 132) = 132
read(7, "\2\0\0\0", 4)                  = 4
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=84056131}) = 0
write(2, "\33[1m", 4)                   = 4
write(2, "2021-01-04 18:37:38.084056 <I> <"..., 61) = 61
write(2, "\33[m", 3)                    = 3
write(6, "\0", 1)                       = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=105219131}) = 0
write(2, "2021-01-04 18:37:38.105219 <D> <"..., 69) = 69
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=113823131}) = 0
write(2, "2021-01-04 18:37:38.113823 <D> <"..., 89) = 89
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=122455131}) = 0
write(2, "2021-01-04 18:37:38.122455 <D> <"..., 64) = 64
epoll_ctl(4, EPOLL_CTL_DEL, 17, 0xbeec9b98) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=134136131}) = 0
write(2, "2021-01-04 18:37:38.134136 <D> <"..., 165) = 165
futex(0xb65414c8, FUTEX_WAIT, 149, NULL) = -1 EAGAIN (Resource temporarily unavailable)
close(19)                               = 0
close(18)                               = 0
close(17)                               = 0
epoll_ctl(4, EPOLL_CTL_DEL, 20, 0xbeec9b98) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=154820131}) = 0
write(2, "2021-01-04 18:37:38.154820 <D> <"..., 165) = 165
futex(0xb5d404c8, FUTEX_WAIT, 150, NULL) = -1 EAGAIN (Resource temporarily unavailable)
close(22)                               = 0
close(21)                               = 0
close(20)                               = 0
epoll_ctl(4, EPOLL_CTL_DEL, 23, 0xbeec9b98) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=170188131}) = 0
write(2, "2021-01-04 18:37:38.170188 <D> <"..., 165) = 165
futex(0xb553f4c8, FUTEX_WAIT, 151, NULL) = -1 EAGAIN (Resource temporarily unavailable)
close(25)                               = 0
close(24)                               = 0
close(23)                               = 0
epoll_ctl(4, EPOLL_CTL_DEL, 26, 0xbeec9b98) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=182191131}) = 0
write(2, "2021-01-04 18:37:38.182191 <D> <"..., 165) = 165
futex(0xb4d3e4c8, FUTEX_WAIT, 152, NULL) = -1 EAGAIN (Resource temporarily unavailable)
close(28)                               = 0
close(27)                               = 0
close(26)                               = 0
epoll_ctl(4, EPOLL_CTL_DEL, 29, 0xbeec9b98) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=188776131}) = 0
write(2, "2021-01-04 18:37:38.188776 <D> <"..., 166) = 166
futex(0xb453d4c8, FUTEX_WAIT, 153, NULL) = 0
munmap(0xb5d41000, 8392704)             = 0
close(31)                               = 0
close(30)                               = 0
close(29)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=195772131}) = 0
write(2, "2021-01-04 18:37:38.195772 <D> <"..., 72) = 72
epoll_ctl(4, EPOLL_CTL_DEL, 16, 0xbeec9b90) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=198910131}) = 0
write(2, "2021-01-04 18:37:38.198910 <D> <"..., 149) = 149
shutdown(16, SHUT_RDWR)                 = 0
close(16)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=202787131}) = 0
write(2, "2021-01-04 18:37:38.202787 <D> <"..., 79) = 79
epoll_ctl(4, EPOLL_CTL_DEL, 15, 0xbeec9b90) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=205766131}) = 0
write(2, "2021-01-04 18:37:38.205766 <D> <"..., 144) = 144
shutdown(15, SHUT_RDWR)                 = 0
close(15)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=209058131}) = 0
write(2, "2021-01-04 18:37:38.209058 <D> <"..., 71) = 71
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=211671131}) = 0
gettid()                                = 147
write(2, "[111.918110] [00000093] libusb: "..., 99) = 99
write(13, "\1", 1)                      = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=214981131}) = 0
gettid()                                = 147
write(2, "[111.921420] [00000093] libusb: "..., 99) = 99
epoll_ctl(4, EPOLL_CTL_DEL, 12, 0xbeec9b98) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=218071131}) = 0
write(2, "2021-01-04 18:37:38.218071 <D> <"..., 142) = 142
epoll_ctl(4, EPOLL_CTL_DEL, 14, 0xbeec9b98) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=220968131}) = 0
write(2, "2021-01-04 18:37:38.220968 <D> <"..., 142) = 142
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=223545131}) = 0
gettid()                                = 147
write(2, "[111.929984] [00000093] libusb: "..., 53) = 53
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=226202131}) = 0
gettid()                                = 147
write(2, "[111.932641] [00000093] libusb: "..., 79) = 79
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=228956131}) = 0
gettid()                                = 147
write(2, "[111.935395] [00000093] libusb: "..., 106) = 106
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=232075131}) = 0
gettid()                                = 147
write(2, "[111.938514] [00000093] libusb: "..., 106) = 106
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=234869131}) = 0
gettid()                                = 147
write(2, "[111.941308] [00000093] libusb: "..., 108) = 108
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=237618131}) = 0
gettid()                                = 147
write(2, "[111.944057] [00000093] libusb: "..., 87) = 87
poll([{fd=12, events=POLLIN}, {fd=14, events=POLLIN}], 2, 0) = 1 ([{fd=12, revents=POLLIN}])
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=240842131}) = 0
gettid()                                = 147
write(2, "[111.947281] [00000093] libusb: "..., 72) = 72
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=243583131}) = 0
gettid()                                = 147
write(2, "[111.950022] [00000093] libusb: "..., 86) = 86
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=246416131}) = 0
gettid()                                = 147
write(2, "[111.952855] [00000093] libusb: "..., 88) = 88
read(12, "\1", 1)                       = 1
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=249892131}) = 0
gettid()                                = 147
write(2, "[111.956331] [00000093] libusb: "..., 79) = 79
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=253011131}) = 0
gettid()                                = 147
write(2, "[111.959450] [00000093] libusb: "..., 79) = 79
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=255726131}) = 0
gettid()                                = 147
write(2, "[111.962165] [00000093] libusb: "..., 79) = 79
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=258410131}) = 0
gettid()                                = 147
write(2, "[111.964849] [00000093] libusb: "..., 72) = 72
write(13, "\1", 1)                      = 1
close(12)                               = 0
close(13)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=262519131}) = 0
gettid()                                = 147
write(2, "[111.968958] [00000093] libusb: "..., 72) = 72
close(14)                               = 0
write(11, "\1", 1)                      = 1
munmap(0xb5540000, 8392704)             = 0
close(9)                                = 0
close(10)                               = 0
close(11)                               = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=270653131}) = 0
write(2, "2021-01-04 18:37:38.270653 <D> <"..., 87) = 87
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=273240131}) = 0
write(2, "2021-01-04 18:37:38.273240 <D> <"..., 80) = 80
rt_sigaction(SIGUSR1, {sa_handler=SIG_DFL, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=0x12144, sa_mask=[USR1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
rt_sigaction(SIGHUP, {sa_handler=SIG_DFL, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=0x12144, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_DFL, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
rt_sigaction(SIGTERM, {sa_handler=SIG_DFL, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=0x12144, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, {sa_handler=0x12144, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0xb6d71010}, 8) = 0
epoll_ctl(4, EPOLL_CTL_DEL, 7, 0xbeec9bb8) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=278570131}) = 0
write(2, "2021-01-04 18:37:38.278570 <D> <"..., 143) = 143
close(7)                                = 0
close(8)                                = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=281992131}) = 0
write(2, "2021-01-04 18:37:38.281992 <D> <"..., 75) = 75
epoll_ctl(4, EPOLL_CTL_DEL, 5, 0xbeec9b88) = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=285071131}) = 0
write(2, "2021-01-04 18:37:38.285071 <D> <"..., 147) = 147
close(5)                                = 0
close(6)                                = 0
close(4)                                = 0
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=289041131}) = 0
write(2, "2021-01-04 18:37:38.289041 <D> <"..., 156) = 156
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=291479131}) = 0
write(2, "2021-01-04 18:37:38.291479 <D> <"..., 155) = 155
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=294044131}) = 0
write(2, "2021-01-04 18:37:38.294044 <D> <"..., 155) = 155
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=296735131}) = 0
write(2, "2021-01-04 18:37:38.296735 <D> <"..., 155) = 155
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=299228131}) = 0
write(2, "2021-01-04 18:37:38.299228 <D> <"..., 155) = 155
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=301883131}) = 0
write(2, "2021-01-04 18:37:38.301883 <D> <"..., 139) = 139
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=304472131}) = 0
write(2, "2021-01-04 18:37:38.304472 <D> <"..., 134) = 134
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=306948131}) = 0
write(2, "2021-01-04 18:37:38.306948 <D> <"..., 132) = 132
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=309378131}) = 0
write(2, "2021-01-04 18:37:38.309378 <D> <"..., 132) = 132
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=311938131}) = 0
write(2, "2021-01-04 18:37:38.311938 <D> <"..., 133) = 133
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=314405131}) = 0
write(2, "2021-01-04 18:37:38.314405 <D> <"..., 137) = 137
clock_gettime64(CLOCK_REALTIME, {tv_sec=1609785458, tv_nsec=316855131}) = 0
write(2, "\33[1m", 4)                   = 4
write(2, "2021-01-04 18:37:38.316855 <I> <"..., 77) = 77
write(2, "\33[m", 3)                    = 3
unlink("/var/run/brickd.pid")           = 0
close(3)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

 

 

Edited by lapawa
Link to post
Share on other sites

Ich habe noch ein paar Angaben zu den Taktfrequenzen des RPi Zero gesammelt:

vcgencmd    vchiq_test  vcmailbox   vconfig     vcsmem
# cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq
1000000
# vcgencmd measure_clock arm
frequency(48)=1000104000
# cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor 
performance
# vcgencmd measure_clock core
frequency(1)=400000000

 

Link to post
Share on other sites

Bezüglich der Taktfrequenzen: Brick Daemon bis einschließlich 2.4.2 erwartet eine core-Clock von 250 MHz (die die du mit

vcgencmd measure_clock core

ausgelesen hast). Beim Pi Zero kannst du die Frequenz mit core_freq=250 in /boot/config.txt festlegen. Die Umbauarbeiten in 2.4.2 und 2.4.3 sind genau dafür da solche Probleme zu umgehen, der Pi skaliert nämlich die SPI-Clock mit der core_freq, d.h. wenn er auf 400 MHz läuft, läuft SPI so schnell, dass die Bricklets das nicht mehr verstehen.

On 1/4/2021 at 8:13 PM, lapawa said:

dass brickd ständig write Zugriffe auf libusb ausführt. Und dies obwohl das HAT per SPI mit den Bricklets kommuniziert.

Das liegt vermutlich daran, dass der Brick Daemon für den Pi auch Stacks per USB unterstützt. Das ist keine spezielle gestrippte Version, die nur SPI kann.

On 1/4/2021 at 8:13 PM, lapawa said:

dass die GPIO Exports beim Beenden von brickd nicht wieder beim Kernel abgemeldet werden.

Das ist interessant, dazu muss ich @photron mal befragen.

On 1/4/2021 at 8:13 PM, lapawa said:

Zugriff auf die Zeitzonen datei /etc/localtime funktioniert nicht. Da sie nicht existiert.
openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
Ist dies ein Problem für brickd?

Das sollte kein Problem sein, du hast ja ein HAT Zero, das hat sowieso keine RTC an Bord.

On 1/4/2021 at 8:13 PM, lapawa said:

Meine Frage hierzu: Kann der Kernel SPI Treiber das CS Timing nicht besser selbst erledigen? Clock und MasterOut kommt ja auch von dort, oder?

Nein, weil der Kernel nicht genug CS-Pins unterstützt. Meines Wissens nur zwei. Ab Brick Daemon 2.4.2 umgehen wir sowieso das ganze Kernel-Interface und sprechen direkt mit dem BCM2835.

Link to post
Share on other sites
On 1/6/2021 at 11:25 AM, rtrbt said:
On 1/4/2021 at 8:13 PM, lapawa said:

dass die GPIO Exports beim Beenden von brickd nicht wieder beim Kernel abgemeldet werden.

Das ist interessant, dazu muss ich @photron mal befragen.

Das war in 2.4.1 der Fall, das ist in 2.4.2 behoben und in 2.4.3 nicht mehr relevant, da dort die CS Pins im Normalfall nicht mehr durch sysfs gesteuert werden.

On 1/6/2021 at 11:25 AM, rtrbt said:
On 1/4/2021 at 8:13 PM, lapawa said:

Zugriff auf die Zeitzonen datei /etc/localtime funktioniert nicht. Da sie nicht existiert.
openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
Ist dies ein Problem für brickd?

Das sollte kein Problem sein, du hast ja ein HAT Zero, das hat sowieso keine RTC an Bord.

brickd selbst greift nicht auf diese Datei zu, das ist vermutlich irgendwas in glibc oder libusb. Das kannst du ignorieren.

Ich glaube nicht, dass das hier mit dem "Message checksum error" Problem zusammenhängt, dass Superb hat, wie @rtrbt vermutet.

On 1/4/2021 at 8:13 PM, lapawa said:

Die version 2.4.1 hat mir nur ein Stückchen weitergeholfen.

Die Fehlermeldungen sind weg. Eine Verbindung per brickv funktioniert. Jedoch werden weder brick noch bricklets im brickv angezeigt.

brickd 2.4.1 meldet diese Fehler auf Debug Level, was standardmäßig nicht sichtbar ist. Die Debug Logauszüge sehen aber gut aus. Komisch.

Komisch ist dann auch, dass es mit brickd 2.4.1 nicht hilft, die core Clock auf 250MHz zu setzen. Für brickd 2.4.3 ist das setzen von core_freq auf 250 nicht mehr notwendig, da diese Version mit abweichenden core Clock Frequenzen um gehen kann.

Vielleicht ist die BCM2835 Library ein Problem, die wird in brickd 2.4.3 standardmäßig verwenden, in Zusammenhang mit deinem Custom Linux Builds ein Problem. Brickd 2.4.1 verwendet stattdessen spidev und sysfs.

Teste mal bitte folgendes:

Installiere wieder brickd 2.4.3 und setze in /etc/brickd.conf die bricklet.spi.driver Option auf spidev:

bricklet.spi.driver = spidev

Du solltest dann in der Logausgabe

Using spidev backend for Bricklets (forced by config)

anstelle von 

Using BCM2835 backend for Bricklets (Raspberry Pi detected)

stehen. Hilft das?

Wenn das nicht hilft, dann teste bitte mal mit einem Standard Raspbian und Standard brickd 2.4.3 anstelle deines Custom Linux Builds. Nicht das hier ein Hardwaredefekt an HAT oder Raspberry Pi vorliegt. Ist beides schon vorgekommen.

Hast du noch ein anderes Raspberry Pi zur Hand u das testen zu können?

Link to post
Share on other sites

Besten Dank für deine Ausführungen.
Du hast mich mit dem Hinweis auf die Hardware auf die Lösung gebracht!

Auch mit einem auf einer anderen Hardware (RPi Zero W + Zero HAT )funktionierendem Raspbian Linux bekomme ich keine Bricklets angezeigt.

Also muss es an der Hardware liegen.


Mein Ethernet Adapter scheint das Problem zu verursachen.
Ich verwende dieses Modell: https://www.waveshare.com/wiki/ETH/USB_HUB_HAT

Schematics: https://www.waveshare.com/w/upload/0/08/ETH_USB_HUB_HAT.pdf

Und obwohl das Platinchen einen USB Hub besitzt an dem auch der Ethernet Chip hängt, macht es mir Probleme mit den SPI Leitungen.

Denn wenn ich den Layer entferne und einen anderen Ethernet USB Adapter anschließe funktioniert der brickd wie erwartet!

 

Mein Stapel sieht so wie auf dem Bild aus. Das ist meine interim Lösung bis der 7polige Stecker am Master Brick verfügbar ist.

Ein Stapel gleicher Art funktioniert in einem anderen Projekt ganz prima.

 

21-01-11 17-17-00 0115.jpg

Edited by lapawa
Link to post
Share on other sites

Der Schaltplan verwirrt mich. Von der Beschreibung des HATs her scheint der sich nur 5V und 3,3V vom Raspberry Pi Header zu holen. Ich bilde mir auch ein auf dem schwammigen Produktfoto Leiterbahnen zu diesen Pins laufen zu sehen. Die USB Kommunikation läuft dann über diese kleine Adapterplatine. Falls das wirklich so ist sollte das funktionieren können.

35 minutes ago, lapawa said:

Mein Stapel sieht so wie auf dem Bild aus. Das ist meine interim Lösung bis der 7polige Stecker am Master Brick verfügbar ist. Der hat in einem anderen Projekt auch bereits funktioniert.

Genau dieser Aufbau hat schon mal funktioniert, oder ein anderer Aufbau dieser Art? Was hat sich geändert? Hast du vielleicht das klassische Raspberry Pi Problem und du versorgst den Aufbau nicht gut genug mit 5V?

Link to post
Share on other sites

Ich habe es mal umformuliert: "Ein Stapel gleicher Art funktioniert in einem anderen Projekt ganz prima."
Die Stromvesorgung ist es nicht. Testweise versorge ich den Stapel mit einem kurzen Kabel (10cm) am 5V Ausgang eines Step-Down Power Supply. Dieser meldet mir per brickv eine Stromaufnahme von 230mA.

Die USB/Eth Adapterplatine funktioniert sogar ohne RPi Header. Ich habe sie testweise nur mit einem USB Kabel verbunden und weit weg vom RPi betrieben. USB Hub und Ethernet funktionieren bei diesem Aufbau.

Das Zero HAT jedoch nicht!

Die Fehlemeldungen vom brickd variieren auch. Ein paar Beispiele:
 

Quote

2021-01-11 17:56:35.711223 <E> <bricklet_stack.c:396> Frame error (port: A, count: 997)
2021-01-11 17:56:36.215338 <E> <bricklet_stack.c:396> Frame error (port: B, count: 196)

2021-01-11 19:00:51.379807 <E> <bricklet_stack.c:478> Message checksum error (port: B, count: 1)

2021-01-11 19:00:51.421364 <E> <bricklet_stack.c:431> ACK checksum error (port: B, count: 1)

2021-01-11 19:00:51.360066 <E> <bricklet_stack.c:506> Message packet error (port: B, count: 9), invalid response: Invalid UID

 

Link to post
Share on other sites

Nochmal einen Schritt zurück bitte.

Als Referenzaufbau habe ich einen RPiZero WLAN mit Zero HAT und regulärem Raspbian 10 und brickd-2.4.3 aus dem deb Paket verwendet.

Also der einfachste denkbare Aufbau, ohne USB/Ethernet HAT zwischen Zero HAT und Raspberry Pi.
Komplett andere Hardware. Sogar ein zweites Zero HAT.

Konzentrieren wir uns besser auf diesen Aufbau.

 

Hier bekomme ich nämlich die selben Fehlermeldungen.

Details vom Raspbian:

Quote

pi@rpizerow:~ $ lsb_release -a
No LSB modules are available.
Distributor ID:    Raspbian
Description:    Raspbian GNU/Linux 10 (buster)
Release:    10
Codename:    buster
pi@rpizerow:~ $ uname -a
Linux rpizerow 5.4.83+ #1379 Mon Dec 14 13:06:05 GMT 2020 armv6l GNU/Linux

pi@rpizerow:~ $ cat /proc/cpuinfo
processor    : 0
model name    : ARMv6-compatible processor rev 7 (v6l)
BogoMIPS    : 997.08
Features    : half thumb fastmult vfp edsp java tls
CPU implementer    : 0x41
CPU architecture: 7
CPU variant    : 0x0
CPU part    : 0xb76
CPU revision    : 7

Hardware    : BCM2835
Revision    : 9000c1
Serial        : 00000000b82b16d3
Model        : Raspberry Pi Zero W Rev 1.1

 

brickd.log:

Quote

 cat brickd.log                                                                                        07:57:48
2021-01-12 07:52:48.878408 <I> <main_linux.c:367> Brick Daemon 2.4.3 started (pid: 348, daemonized: 1)
2021-01-12 07:52:48.945408 <I> <bricklet.c:270> Found supported HAT product_id 0x085d in device tree, using default HAT Zero Brick config
2021-01-12 07:52:48.945606 <I> <bricklet.c:311> Found Bricklet port A (spidev: /dev/spidev0.0, driver: gpio, name: gpio27, num: 27)
2021-01-12 07:52:48.945981 <I> <bricklet_stack_linux.c:129> Using BCM2835 backend for Bricklets (Raspberry Pi detected)
2021-01-12 07:52:48.976588 <W> <bricklet_stack_linux_bcm2835.c:129> Raspberry Pi core frequency (core_freq: 400, core_freq_min: 250) is unstable, SPI throughput will be unstable too
2021-01-12 07:52:48.976787 <I> <bricklet_stack_linux_bcm2835.c:133> Using 400 MHz Raspberry Pi core frequency (core_freq: 400, core_freq_min: 250) for BCM2835 backend
2021-01-12 07:52:48.978679 <I> <bricklet.c:311> Found Bricklet port B (spidev: /dev/spidev0.0, driver: gpio, name: gpio23, num: 23)
2021-01-12 07:52:48.995596 <I> <bricklet.c:311> Found Bricklet port C (spidev: /dev/spidev0.0, driver: gpio, name: gpio24, num: 24)
2021-01-12 07:52:48.996187 <I> <bricklet.c:311> Found Bricklet port D (spidev: /dev/spidev0.0, driver: gpio, name: gpio22, num: 22)
2021-01-12 07:52:49.012265 <I> <bricklet.c:311> Found Bricklet port E (spidev: /dev/spidev0.0, driver: gpio, name: gpio25, num: 25)
2021-01-12 07:52:50.013209 <E> <bricklet_stack.c:396> Frame error (port: B, count: 1)
2021-01-12 07:52:50.013566 <E> <bricklet_stack.c:396> Frame error (port: C, count: 1)
2021-01-12 07:52:50.014945 <E> <bricklet_stack.c:478> Message checksum error (port: B, count: 1)
2021-01-12 07:52:50.015179 <E> <bricklet_stack.c:396> Frame error (port: D, count: 1)
2021-01-12 07:52:50.017828 <E> <bricklet_stack.c:396> Frame error (port: C, count: 4)
2021-01-12 07:52:50.020377 <E> <bricklet_stack.c:396> Frame error (port: D, count: 5)
2021-01-12 07:52:50.023566 <E> <bricklet_stack.c:396> Frame error (port: C, count: 9)
2021-01-12 07:52:50.025023 <E> <bricklet_stack.c:396> Frame error (port: D, count: 9)
2021-01-12 07:52:50.028166 <E> <bricklet_stack.c:396> Frame error (port: C, count: 13)
2021-01-12 07:52:50.030714 <E> <bricklet_stack.c:396> Frame error (port: D, count: 14)

....

2021-01-12 07:52:51.652950 <E> <bricklet_stack.c:396> Frame error (port: D, count: 993)
2021-01-12 07:52:51.653270 <E> <bricklet_stack.c:396> Frame error (port: C, count: 995)
2021-01-12 07:52:51.658259 <E> <bricklet_stack.c:396> Frame error (port: C, count: 998)
2021-01-12 07:52:51.658489 <E> <bricklet_stack.c:396> Frame error (port: D, count: 997)

 

 

Und nochmal mit brickd im debug logging:

Die ca. 1000 Frame Error Meldungen scheinen nur nach eine Kaltstart aufzutauchen.

Wenn ich nur das Raspbian oder den brickd neu starte bleiben sie aus.

ABER: brickv zeigt die Komponenten an!

Quote

2021-01-12 08:18:05.610620 <I> <main_linux.c:367> Brick Daemon 2.4.3 started (pid: 343, daemonized: 1)
2021-01-12 08:18:05.611683 <D> <main_linux.c:375> Using config file: /etc/brickd.conf
2021-01-12 08:18:05.611776 <D> <main_linux.c:378> Using log file: /var/log/brickd.log
2021-01-12 08:18:05.611848 <D> <main_linux.c:381> Using PID file: /var/run/brickd.pid
2021-01-12 08:18:05.611922 <D> <event.c:60> Initializing event subsystem
2021-01-12 08:18:05.612130 <D> <event|event.c:270> Added generic event source (handle: 6, name: event-stop, events: 0x0001) at index 0
2021-01-12 08:18:05.612283 <D> <event|event.c:270> Added generic event source (handle: 8, name: signal, events: 0x0001) at index 1
2021-01-12 08:18:05.612558 <D> <hardware.c:39> Initializing hardware subsystem
2021-01-12 08:18:05.612742 <D> <usb.c:261> Initializing USB subsystem
2021-01-12 08:18:05.613025 <D> <usb_posix.c:188> Successfully loaded brickd (for libusb symbols)
[timestamp] [threadID] facility level [function call] <message>
--------------------------------------------------------------------------------
[ 0.000075] [00000157] libusb: debug [libusb_init] created default context
[ 0.000281] [00000157] libusb: debug [libusb_init] libusb v1.0.22.11312
[ 0.000591] [00000157] libusb: debug [find_usbfs_path] found usbfs at /dev/bus/usb
[ 0.000739] [00000157] libusb: debug [get_kernel_version] reported kernel version is 5.4.83+
[ 0.000804] [00000157] libusb: debug [op_init] bulk continuation flag supported
[ 0.000859] [00000157] libusb: debug [op_init] zero length packet flag supported
[ 0.000914] [00000157] libusb: debug [op_init] max iso packet length is (likely) 49152 bytes
[ 0.001031] [00000157] libusb: debug [op_init] sysfs can relate devices
[ 0.001096] [00000157] libusb: debug [op_init] sysfs has complete descriptors
[ 0.062821] [00000158] libusb: debug [linux_udev_event_thread_main] udev event thread entering.
[ 0.079705] [00000157] libusb: debug [linux_get_device_address] getting address for device: usb1 detached: 0
[ 0.079862] [00000157] libusb: debug [linux_get_device_address] scan usb1
[ 0.080509] [00000157] libusb: debug [linux_get_device_address] bus=1 dev=1
[ 0.080615] [00000157] libusb: debug [linux_enumerate_device] busnum 1 devaddr 1 session_id 257
[ 0.080711] [00000157] libusb: debug [linux_enumerate_device] allocating new device for 1/1 (session 257)
[ 0.081516] [00000157] libusb: debug [usbi_add_pollfd] add fd 13 events 1
[ 0.081707] [00000157] libusb: debug [usbi_io_init] using timerfd for timeouts
[ 0.081779] [00000157] libusb: debug [usbi_add_pollfd] add fd 15 events 1
2021-01-12 08:18:05.695199 <D> <event|event.c:270> Added USB event source (handle: 13, name: usb-poll, events: 0x0001) at index 2
2021-01-12 08:18:05.695360 <D> <event|event.c:270> Added USB event source (handle: 15, name: usb-poll, events: 0x0001) at index 3
2021-01-12 08:18:05.695485 <D> <usb.c:323> libusb supports hotplug
[ 0.082276] [00000157] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 0x212518 with handle 1
[ 0.082350] [00000157] libusb: debug [libusb_hotplug_register_callback] new hotplug cb 0x2124b8 with handle 2
2021-01-12 08:18:05.695714 <D> <usb.c:334> Starting initial USB device scan
2021-01-12 08:18:05.695790 <D> <usb.c:385> Looking for added/removed USB devices
[ 0.082572] [00000157] libusb: debug [libusb_get_device_list]
2021-01-12 08:18:05.696069 <D> <usb.c:114> Found 1 USB device(s)
[ 0.082894] [00000157] libusb: debug [libusb_get_device_descriptor]
2021-01-12 08:18:05.696287 <D> <network.c:177> Initializing network subsystem
2021-01-12 08:18:05.696386 <D> <socket.c:164> Opening server socket(s) for address '0.0.0.0' on port 4223
2021-01-12 08:18:05.696831 <D> <socket.c:264> Started listening to '0.0.0.0' (IPv4) resolved from '0.0.0.0' on port 4223
2021-01-12 08:18:05.697009 <D> <event|event.c:270> Added generic event source (handle: 16, name: server, events: 0x0001) at index 4
2021-01-12 08:18:05.697112 <D> <mesh.c:53> Initializing mesh subsystem
2021-01-12 08:18:05.697217 <D> <socket.c:164> Opening server socket(s) for address '0.0.0.0' on port 4240
2021-01-12 08:18:05.697582 <D> <socket.c:264> Started listening to '0.0.0.0' (IPv4) resolved from '0.0.0.0' on port 4240
2021-01-12 08:18:05.697730 <D> <event|event.c:270> Added generic event source (handle: 17, name: mesh-server, events: 0x0001) at index 5
2021-01-12 08:18:05.698138 <I> <bricklet.c:270> Found supported HAT product_id 0x085d in device tree, using default HAT Zero Brick config
2021-01-12 08:18:05.698270 <I> <bricklet.c:311> Found Bricklet port A (spidev: /dev/spidev0.0, driver: gpio, name: gpio27, num: 27)
2021-01-12 08:18:05.698348 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port A
2021-01-12 08:18:05.698575 <D> <event|event.c:270> Added generic event source (handle: 18, name: bricklet-stack-notification, events: 0x0001) at index 6
2021-01-12 08:18:05.698809 <I> <bricklet_stack_linux.c:129> Using BCM2835 backend for Bricklets (Raspberry Pi detected)
2021-01-12 08:18:05.738562 <D> <bricklet_stack_linux_bcm2835.c:80> Raspberry Pi core_freq_min value is zero, assuming 250 MHz
2021-01-12 08:18:05.738751 <W> <bricklet_stack_linux_bcm2835.c:129> Raspberry Pi core frequency (core_freq: 400, core_freq_min: 250) is unstable, SPI throughput will be unstable too
2021-01-12 08:18:05.738832 <I> <bricklet_stack_linux_bcm2835.c:133> Using 400 MHz Raspberry Pi core frequency (core_freq: 400, core_freq_min: 250) for BCM2835 backend
2021-01-12 08:18:05.748733 <I> <bricklet.c:311> Found Bricklet port B (spidev: /dev/spidev0.0, driver: gpio, name: gpio23, num: 23)
2021-01-12 08:18:05.757466 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port B
2021-01-12 08:18:05.757749 <D> <event|event.c:270> Added generic event source (handle: 19, name: bricklet-stack-notification, events: 0x0001) at index 7
2021-01-12 08:18:05.765174 <I> <bricklet.c:311> Found Bricklet port C (spidev: /dev/spidev0.0, driver: gpio, name: gpio24, num: 24)
2021-01-12 08:18:05.765353 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port C
2021-01-12 08:18:05.765526 <D> <event|event.c:270> Added generic event source (handle: 20, name: bricklet-stack-notification, events: 0x0001) at index 8
2021-01-12 08:18:05.765936 <I> <bricklet.c:311> Found Bricklet port D (spidev: /dev/spidev0.0, driver: gpio, name: gpio22, num: 22)
2021-01-12 08:18:05.766058 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port D
2021-01-12 08:18:05.766234 <D> <event|event.c:270> Added generic event source (handle: 21, name: bricklet-stack-notification, events: 0x0001) at index 9
2021-01-12 08:18:05.766626 <I> <bricklet.c:311> Found Bricklet port E (spidev: /dev/spidev0.0, driver: gpio, name: gpio25, num: 25)
2021-01-12 08:18:05.766745 <D> <bricklet_stack.c:725> Initializing Bricklet stack subsystem for port E
2021-01-12 08:18:05.766904 <D> <event|event.c:270> Added generic event source (handle: 22, name: bricklet-stack-notification, events: 0x0001) at index 10
2021-01-12 08:18:05.767262 <D> <event.c:534> Starting the event loop
2021-01-12 08:18:05.767406 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-12 08:18:05.767532 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:05.767614 <D> <event|event.c:447> Handling USB event source (handle: 13, name: usb-poll, received-events: 0x0001)
[ 0.154456] [00000157] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[ 0.154566] [00000157] libusb: debug [handle_events] poll fds modified, reallocating
[ 0.154668] [00000157] libusb: debug [handle_events] poll() 2 fds with timeout in 0ms
[ 0.154747] [00000157] libusb: debug [handle_events] poll() returned 0
2021-01-12 08:18:05.768130 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:05.768222 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-12 08:18:05.797622 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:05.797826 <D> <event|event.c:447> Handling generic event source (handle: 22, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-12 08:18:05.798130 <D> <packet|network.c:459> No clients connected, dropping enumerate-connected callback (U: LEY, L: 34, F: 253, I: 0, packet: 04 4B 02 00 22 FD 08 00 4C 45 59 00 00 00 00 00 30 00 00 00 00 00 00 00 65 01 00 00 02 00 01 70 00 01)
2021-01-12 08:18:05.798241 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:05.798322 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-12 08:18:05.805542 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:05.805734 <D> <event|event.c:447> Handling generic event source (handle: 22, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-12 08:18:05.805921 <D> <packet|network.c:459> No clients connected, dropping enumerate-connected callback (U: LEY, L: 34, F: 253, I: 0, packet: 04 4B 02 00 22 FD 08 00 4C 45 59 00 00 00 00 00 30 00 00 00 00 00 00 00 65 01 00 00 02 00 01 70 00 01)
2021-01-12 08:18:05.806124 <D> <packet|network.c:459> No clients connected, dropping enumerate-connected callback (U: LEY, L: 34, F: 253, I: 0, packet: 04 4B 02 00 22 FD 08 00 4C 45 59 00 00 00 00 00 30 00 00 00 00 00 00 00 65 01 00 00 02 00 01 70 00 01)
2021-01-12 08:18:05.806222 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:05.806303 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-12 08:18:06.793230 <E> <bricklet_stack.c:396> Frame error (port: C, count: 1)
2021-01-12 08:18:06.798305 <E> <bricklet_stack.c:396> Frame error (port: C, count: 5)
2021-01-12 08:18:06.799799 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:06.800013 <D> <event|event.c:447> Handling generic event source (handle: 19, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-12 08:18:06.800203 <D> <packet|network.c:459> No clients connected, dropping enumerate-connected callback (U: KC2, L: 34, F: 253, I: 0, packet: 35 3D 02 00 22 FD 08 00 4B 43 32 00 00 00 00 00 4C 45 59 00 00 00 00 00 62 01 00 00 02 00 01 68 08 01)
2021-01-12 08:18:06.800304 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:06.800384 <D> <event|event_linux.c:147> Starting to epoll on 11 event source(s)
2021-01-12 08:18:06.804341 <E> <bricklet_stack.c:396> Frame error (port: C, count: 9)
2021-01-12 08:18:06.809369 <E> <bricklet_stack.c:396> Frame error (port: C, count: 13)
2021-01-12 08:18:06.814924 <E> <bricklet_stack.c:396> Frame error (port: C, count: 17)
2021-01-12 08:18:06.819723 <E> <bricklet_stack.c:396> Frame error (port: C, count: 21)

...
2021-01-12 08:18:08.263282 <E> <bricklet_stack.c:396> Frame error (port: C, count: 981)
2021-01-12 08:18:08.268295 <E> <bricklet_stack.c:396> Frame error (port: C, count: 985)
2021-01-12 08:18:08.273459 <E> <bricklet_stack.c:396> Frame error (port: C, count: 989)
2021-01-12 08:18:08.278544 <E> <bricklet_stack.c:396> Frame error (port: C, count: 993)
2021-01-12 08:18:08.283724 <E> <bricklet_stack.c:396> Frame error (port: C, count: 997)
2021-01-12 08:18:14.569019 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:14.569263 <D> <event|event.c:447> Handling generic event source (handle: 16, name: server, received-events: 0x0001)
2021-01-12 08:18:14.569566 <D> <client.c:382> Creating client from plain-socket (handle: 23/23)
2021-01-12 08:18:14.569738 <D> <event|event.c:270> Added generic event source (handle: 23, name: client, events: 0x0001) at index 11
2021-01-12 08:18:14.569854 <I> <network.c:304> Added new client (N: 192.168.77.4:58120, T: plain-socket, H: 23/23, B: 0, P: 0, A: disabled)
2021-01-12 08:18:14.569957 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:14.570058 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-12 08:18:14.654500 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:14.654692 <D> <event|event.c:447> Handling generic event source (handle: 23, name: client, received-events: 0x0001)
2021-01-12 08:18:14.654923 <D> <packet|client.c:324> Received request (U: 1, L: 8, F: 254, S: 9, R: 0, I: 0, packet: 00 00 00 00 08 FE 90 00) from client (N: 192.168.77.4:58120, T: plain-socket, H: 23/23, B: 8, P: 0, A: disabled)
2021-01-12 08:18:14.655058 <D> <packet|hardware.c:115> Broadcasting request (U: 1, L: 8, F: 254, S: 9, R: 0, I: 0, packet: 00 00 00 00 08 FE 90 00) to 5 stack(s)
2021-01-12 08:18:14.655140 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-12 08:18:14.655260 <D> <packet|bricklet_stack.c:88> Packet is queued to be send over SPI (U: 1, L: 8, F: 254, S: 9, R: 0, I: 0, packet: 00 00 00 00 08 FE 90 00)
2021-01-12 08:18:14.655336 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-12 08:18:14.655408 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-12 08:18:14.655480 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-12 08:18:14.655587 <D> <packet|bricklet_stack.c:88> Packet is queued to be send over SPI (U: 1, L: 8, F: 254, S: 9, R: 0, I: 0, packet: 00 00 00 00 08 FE 90 00)
2021-01-12 08:18:14.655659 <D> <packet|stack.c:134> Forced to sent request to Bricklet-/dev/spidev0.0
2021-01-12 08:18:14.655745 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:14.655827 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-12 08:18:14.656921 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:14.657061 <D> <event|event.c:447> Handling generic event source (handle: 19, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-12 08:18:14.657239 <D> <packet|network.c:467> Broadcasting enumerate-available callback (U: KC2, L: 34, F: 253, I: 0, packet: 35 3D 02 00 22 FD 08 00 4B 43 32 00 00 00 00 00 4C 45 59 00 00 00 00 00 62 01 00 00 02 00 01 68 08 00) to 1 client(s)
2021-01-12 08:18:14.657766 <D> <packet|client.c:508> Forced to send response to client (N: 192.168.77.4:58120, T: plain-socket, H: 23/23, B: 0, P: 0, A: disabled)
2021-01-12 08:18:14.657941 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:14.658025 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-12 08:18:14.660824 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:14.660980 <D> <event|event.c:447> Handling generic event source (handle: 22, name: bricklet-stack-notification, received-events: 0x0001)
2021-01-12 08:18:14.661167 <D> <packet|network.c:467> Broadcasting enumerate-available callback (U: LEY, L: 34, F: 253, I: 0, packet: 04 4B 02 00 22 FD 08 00 4C 45 59 00 00 00 00 00 30 00 00 00 00 00 00 00 65 01 00 00 02 00 01 70 00 00) to 1 client(s)
2021-01-12 08:18:14.661678 <D> <packet|client.c:508> Forced to send response to client (N: 192.168.77.4:58120, T: plain-socket, H: 23/23, B: 0, P: 0, A: disabled)
2021-01-12 08:18:14.661852 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:14.661939 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-12 08:18:24.862740 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:24.863026 <D> <event|event.c:447> Handling generic event source (handle: 23, name: client, received-events: 0x0001)
2021-01-12 08:18:24.863181 <D> <packet|client.c:314> Received disconnect probe from client (N: 192.168.77.4:58120, T: plain-socket, H: 23/23, B: 8, P: 0, A: disabled), dropping request
2021-01-12 08:18:24.863297 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:24.863399 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-12 08:18:29.775071 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:18:29.775311 <D> <event|event.c:447> Handling generic event source (handle: 23, name: client, received-events: 0x0001)
2021-01-12 08:18:29.775460 <D> <packet|client.c:314> Received disconnect probe from client (N: 192.168.77.4:58120, T: plain-socket, H: 23/23, B: 8, P: 0, A: disabled), dropping request
2021-01-12 08:18:29.775577 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:18:29.775677 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-12 08:19:04.575600 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:19:04.575841 <D> <event|event.c:447> Handling generic event source (handle: 23, name: client, received-events: 0x0001)
2021-01-12 08:19:04.575992 <D> <packet|client.c:314> Received disconnect probe from client (N: 192.168.77.4:58120, T: plain-socket, H: 23/23, B: 8, P: 0, A: disabled), dropping request
2021-01-12 08:19:04.576107 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:19:04.576207 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)
2021-01-12 08:19:09.460393 <D> <event|event_linux.c:166> EPoll returned 1 event source(s) as ready
2021-01-12 08:19:09.460621 <D> <event|event.c:447> Handling generic event source (handle: 23, name: client, received-events: 0x0001)
2021-01-12 08:19:09.460748 <D> <packet|client.c:314> Received disconnect probe from client (N: 192.168.77.4:58120, T: plain-socket, H: 23/23, B: 8, P: 0, A: disabled), dropping request
2021-01-12 08:19:09.460846 <D> <event|event_linux.c:179> Handled all ready event sources
2021-01-12 08:19:09.460931 <D> <event|event_linux.c:147> Starting to epoll on 12 event source(s)

 

 

 

 

Edited by lapawa
Link to post
Share on other sites

Finally solved!

Es war ein reines Problem mit der Hardware. Hier wurde mit zu viel Lötzinn gearbeitet.

Durch das ETH/USB HAT wurde ausgerechnet Pin 17+21 also SPI-MISO und SPI-MOSI gebrückt!

Siehe Bild:

1007348007_21-01-1210-42-040126.thumb.jpg.a62d7eac0df8ff41355d91cf49d35ea1.jpg

 

Also Klecks entfernt und alles ist wieder gut!

Danke für die rege Teilnahme an der Problemlösung. Endlich kann es mit dem Projekt weitergehen.

Ich freue mich auf einen Master Brick mit 7poligem Stecker. Die sind wenigstens auf Funktion geprüft und ersparen mir zeitraubenden Fehlersuchen dieser Art.

 

Link to post
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.

Guest
Reply to this topic...

×   Pasted as rich text.   Paste as plain text instead

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

×
×
  • Create New...