Closed teon closed 7 months ago
[2023-10-23][12:19:30][TRACE][async_io::driver] block_on() [2023-10-23][12:19:30][TRACE][polling::epoll] add: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: false, writable: false } [2023-10-23][12:19:30][TRACE][polling::epoll] add: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][polling::epoll] new: epoll_fd=20, event_fd=21, timer_fd=Some(22) [2023-10-23][12:19:30][TRACE][polling::epoll] add: epoll_fd=20, fd=19, ev=Event { key: 0, readable: false, writable: false } [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: false, writable: true } [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][polling::epoll] new events: epoll_fd=20, res=1 [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::reactor] react: 1 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: sleeping for 50 us [2023-10-23][12:19:30][TRACE][async_io::reactor] writable: fd=19 [2023-10-23][12:19:30][INFO][tracing::span] perform; [2023-10-23][12:19:30][TRACE][zbus::handshake] Initializing [2023-10-23][12:19:30][INFO][zbus::handshake] write_command; command=Auth(Some(External), Some([49, 48, 48, 48])) [2023-10-23][12:19:30][TRACE][tracing::span] -- write_command; [2023-10-23][12:19:30][TRACE][zbus::handshake] Waiting for DATA or OK from server [2023-10-23][12:19:30][INFO][tracing::span] read_command; [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][polling::epoll] new events: epoll_fd=20, res=1 [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::reactor] react: 1 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: sleeping for 50 us [2023-10-23][12:19:30][TRACE][tracing::span] -- read_command; [2023-10-23][12:19:30][TRACE][zbus::handshake] Received OK from server [2023-10-23][12:19:30][INFO][zbus::handshake] write_command; command=NegotiateUnixFD [2023-10-23][12:19:30][TRACE][tracing::span] -- write_command; [2023-10-23][12:19:30][TRACE][zbus::handshake] Waiting for Unix FD passing agreement from server [2023-10-23][12:19:30][INFO][tracing::span] read_command; [2023-10-23][12:19:30][TRACE][tracing::span] -- read_command; [2023-10-23][12:19:30][TRACE][zbus::handshake] Unix FD passing agreed by server [2023-10-23][12:19:30][INFO][zbus::handshake] write_command; command=Begin [2023-10-23][12:19:30][TRACE][tracing::span] -- write_command; [2023-10-23][12:19:30][TRACE][zbus::handshake] Handshake done [2023-10-23][12:19:30][TRACE][tracing::span] -- perform; [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][INFO][zbus::connection] start_object_server; started_event=Some(Event { .. }) [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][tracing::span::active] -> start_object_server; [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][zbus::connection] starting ObjectServer task [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][INFO][zbus::connection] {}; obj_server_task_name="ObjectServer task" [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][tracing::span::active] <- start_object_server; [2023-10-23][12:19:30][TRACE][tracing::span] -- start_object_server; [2023-10-23][12:19:30][TRACE][tracing::span::active] -> {}; [2023-10-23][12:19:30][TRACE][zbus::connection] waiting for incoming method call messages.. [2023-10-23][12:19:30][TRACE][tracing::span::active] <- {}; [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: notified [2023-10-23][12:19:30][TRACE][zbus::connection] Sending message: Msg { type: MethodCall, path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("Hello"))) } [2023-10-23][12:19:30][TRACE][zbus::connection] Sent message with serial: 1 [2023-10-23][12:19:30][INFO][tracing::span] socket reader; [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: notified [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][TRACE][polling::epoll] new events: epoll_fd=20, res=1 [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::reactor] react: 1 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: sleeping for 50 us [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Message received on the socket: Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 1, body: Signature("s") } [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Error broadcasting message to stream for `None`: SendError(..) [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Broadcasted to all streams: Ok(Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 1, body: Signature("s") }) [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Message received on the socket: Msg { type: Signal, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("NameAcquired"))), body: Signature("s") } [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Error broadcasting message to stream for `None`: SendError(..) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Broadcasted to all streams: Ok(Msg { type: Signal, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("NameAcquired"))), body: Signature("s") }) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: notified [2023-10-23][12:19:30][TRACE][zbus::connection] Sending message: Msg { type: MethodCall, sender: UniqueName(Str(Borrowed(":1.7392"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("AddMatch"))), body: Signature("s") } [2023-10-23][12:19:30][TRACE][zbus::connection] Sent message with serial: 2 [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][TRACE][polling::epoll] new events: epoll_fd=20, res=1 [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::reactor] react: 1 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: sleeping for 50 us [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Message received on the socket: Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 2 } [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Error broadcasting message to stream for `None`: SendError(..) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Broadcasted to all streams: Ok(Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 2 }) [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: notified [2023-10-23][12:19:30][TRACE][zbus::connection] Sending message: Msg { type: MethodCall, sender: UniqueName(Str(Borrowed(":1.7392"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("AddMatch"))), body: Signature("s") } [2023-10-23][12:19:30][TRACE][zbus::connection] Sent message with serial: 3 [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][TRACE][polling::epoll] new events: epoll_fd=20, res=1 [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::reactor] react: 1 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: sleeping for 50 us [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Message received on the socket: Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 3 } [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Error broadcasting message to stream for `None`: SendError(..) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Broadcasted to all streams: Ok(Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 3 }) [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: notified [2023-10-23][12:19:30][TRACE][zbus::connection] Sending message: Msg { type: MethodCall, sender: UniqueName(Str(Borrowed(":1.7392"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("RequestName"))), body: Signature("su") } [2023-10-23][12:19:30][TRACE][zbus::connection] Sent message with serial: 4 [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][TRACE][polling::epoll] new events: epoll_fd=20, res=1 [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::reactor] react: 1 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: sleeping for 50 us [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Message received on the socket: Msg { type: Signal, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("NameAcquired"))), body: Signature("s") } [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Error broadcasting message to stream for `None`: SendError(..) [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Broadcasted to all streams: Ok(Msg { type: Signal, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("NameAcquired"))), body: Signature("s") }) [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Message received on the socket: Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 4, body: Signature("u") } [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Error broadcasting message to stream for `None`: SendError(..) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Broadcasted to all streams: Ok(Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 4, body: Signature("u") }) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: notified [2023-10-23][12:19:30][TRACE][zbus::connection] {}; task_name="Remove match `type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameLost',path='/org/freedesktop/DBus'`" [2023-10-23][12:19:30][TRACE][zbus::connection] {}; task_name="Remove match `type='signal',sender='org.freedesktop.DBus',interface='org.freedesktop.DBus',member='NameAcquired',path='/org/freedesktop/DBus'`" [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: completed [2023-10-23][12:19:30][TRACE][async_io::driver] block_on() [2023-10-23][12:19:30][TRACE][tracing::span::active] -> {}; [2023-10-23][12:19:30][TRACE][zbus::connection] Sending message: Msg { type: MethodCall, sender: UniqueName(Str(Borrowed(":1.7392"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("RemoveMatch"))), body: Signature("s") } [2023-10-23][12:19:30][TRACE][zbus::connection] Sent message with serial: 5 [2023-10-23][12:19:30][TRACE][tracing::span::active] <- {}; [2023-10-23][12:19:30][TRACE][tracing::span::active] -> {}; [2023-10-23][12:19:30][TRACE][tracing::span::active] <- {}; [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][TRACE][polling::epoll] new events: epoll_fd=20, res=1 [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::reactor] react: 1 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: sleeping for 50 us [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: notified [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Message received on the socket: Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 5 } [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Error broadcasting message to stream for `None`: SendError(..) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Broadcasted to all streams: Ok(Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 5 }) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][tracing::span::active] -> {}; [2023-10-23][12:19:30][TRACE][tracing::span::active] <- {}; [2023-10-23][12:19:30][TRACE][tracing::span::active] -> {}; [2023-10-23][12:19:30][TRACE][tracing::span::active] <- {}; [2023-10-23][12:19:30][TRACE][tracing::span] -- {}; [2023-10-23][12:19:30][TRACE][tracing::span::active] -> {}; [2023-10-23][12:19:30][TRACE][zbus::connection] Sending message: Msg { type: MethodCall, sender: UniqueName(Str(Borrowed(":1.7392"))), path: ObjectPath("/org/freedesktop/DBus"), iface: InterfaceName(Str(Borrowed("org.freedesktop.DBus"))), member: MemberName(Str(Borrowed("RemoveMatch"))), body: Signature("s") } [2023-10-23][12:19:30][TRACE][zbus::connection] Sent message with serial: 6 [2023-10-23][12:19:30][TRACE][tracing::span::active] <- {}; [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][TRACE][polling::epoll] new events: epoll_fd=20, res=1 [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=21, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][async_io::reactor] react: 1 ready wakers [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: sleeping for 50 us [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Message received on the socket: Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 6 } [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Error broadcasting message to stream for `None`: SendError(..) [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Broadcasted to all streams: Ok(Msg { type: MethodReturn, sender: UniqueName(Str(Borrowed("org.freedesktop.DBus"))), reply-serial: 6 }) [2023-10-23][12:19:30][TRACE][async_io::driver] main_loop: waiting on I/O [2023-10-23][12:19:30][TRACE][async_io::reactor] process_timers: 0 ready wakers [2023-10-23][12:19:30][TRACE][zbus::socket_reader] Waiting for message on the socket.. [2023-10-23][12:19:30][TRACE][polling] Poller::wait(_, None) [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=19, ev=Event { key: 0, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][polling::epoll] wait: epoll_fd=20, timeout=None [2023-10-23][12:19:30][TRACE][tracing::span::active] -> {}; [2023-10-23][12:19:30][TRACE][polling::epoll] modify: epoll_fd=20, fd=22, ev=Event { key: 18446744073709551615, readable: true, writable: false } [2023-10-23][12:19:30][TRACE][tracing::span::active] <- {}; [2023-10-23][12:19:30][TRACE][tracing::span::active] -> {}; [2023-10-23][12:19:30][TRACE][tracing::span::active] <- {}; [2023-10-23][12:19:30][TRACE][tracing::span] -- {}; [2023-10-23][12:19:30][TRACE][async_io::driver] block_on: sleep until notification [2023-10-23][12:19:30][DEBUG][defguard_client] Initializing database connection [2023-10-23][12:19:30][DEBUG][defguard_client::database] Creating app data dir at: /home/teon/.local/share/net.defguard [2023-10-23][12:19:30][INFO][defguard_client::database] Created app data dir at: /home/teon/.local/share/net.defguard [2023-10-23][12:19:30][DEBUG][defguard_client::database] Database not found creating database file at: /home/teon/.local/share/net.defguard/defguard.db [2023-10-23][12:19:30][INFO][defguard_client::database] Database file succesfully created at: /home/teon/.local/share/net.defguard/defguard.db [2023-10-23][12:19:30][DEBUG][defguard_client::database] Connecting to database: /home/teon/.local/share/net.defguard/defguard.db [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="PRAGMA foreign_keys = ON; …" db.statement="\n\nPRAGMA foreign_keys = ON;\n" rows_affected=0 rows_returned=0 elapsed=58.921µs [2023-10-23][12:19:30][DEBUG][defguard_client::database] Running migrations. [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="CREATE TABLE IF NOT …" db.statement="\n\nCREATE TABLE IF NOT EXISTS _sqlx_migrations (\n version BIGINT PRIMARY KEY,\n description TEXT NOT NULL,\n installed_on TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP,\n success BOOLEAN NOT NULL,\n checksum BLOB NOT NULL,\n execution_time BIGINT NOT NULL\n);\n" rows_affected=0 rows_returned=0 elapsed=16.278075ms [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="SELECT version FROM _sqlx_migrations …" db.statement="\n\nSELECT\n version\nFROM\n _sqlx_migrations\nWHERE\n success = false\nORDER BY\n version\nLIMIT\n 1\n" rows_affected=0 rows_returned=0 elapsed=120.096µs [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="SELECT version, checksum FROM …" db.statement="\n\nSELECT\n version,\n checksum\nFROM\n _sqlx_migrations\nORDER BY\n version\n" rows_affected=0 rows_returned=0 elapsed=36.167µs [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="CREATE TABLE instance ( …" db.statement="\n\nCREATE TABLE instance (\n id INTEGER PRIMARY KEY AUTOINCREMENT,\n uuid TEXT NOT NULL,\n name TEXT NOT NULL,\n url TEXT NOT NULL\n);\nCREATE TABLE location (\n id INTEGER PRIMARY KEY AUTOINCREMENT,\n instance_id INTEGER NOT NULL,\n network_id INTEGER NOT NULL,\n -- Native id of network in defguard system\n name TEXT NOT NULL,\n address TEXT NOT NULL,\n pubkey TEXT NOT NULL,\n endpoint TEXT NOT NULL,\n allowed_ips TEXT NOT NULL,\n dns TEXT,\n FOREIGN KEY (instance_id) REFERENCES instance(id)\n);\n-- Create the Connection table\nCREATE TABLE connection (\n id INTEGER PRIMARY KEY AUTOINCREMENT,\n location_id INTEGER NOT NULL,\n connected_from TEXT NOT NULL,\n -- Renamed from 'from' as it reserved\n start TIMESTAMP NOT NULL,\nend TIMESTAMP NOT NULL,\nFOREIGN KEY (location_id) REFERENCES location(id)\n);\n-- Create the LocationStats table\nCREATE TABLE location_stats (\n id INTEGER PRIMARY KEY AUTOINCREMENT,\n location_id INTEGER NOT NULL,\n upload INTEGER NOT NULL,\n download INTEGER NOT NULL,\n last_handshake INTEGER NOT NULL,\n collected_at TIMESTAMP NOT NULL,\n FOREIGN KEY (location_id) REFERENCES location(id)\n);\n-- Create the LocationStats table\nCREATE TABLE wireguard_keys (\n id INTEGER PRIMARY KEY AUTOINCREMENT,\n instance_id INTEGER NOT NULL,\n pubkey TEXT NOT NULL,\n prvkey TEXT NOT NULL,\n FOREIGN KEY (instance_id) REFERENCES instance(id)\n);\n" rows_affected=0 rows_returned=0 elapsed=402.916µs [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="INSERT INTO _sqlx_migrations ( …" db.statement="\n\nINSERT INTO\n _sqlx_migrations (\n version,\n description,\n success,\n checksum,\n execution_time\n )\nVALUES\n (?1, ?2, TRUE, ?3, -1)\n" rows_affected=1 rows_returned=0 elapsed=73.999µs [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="UPDATE _sqlx_migrations SET execution_time …" db.statement="\n\nUPDATE\n _sqlx_migrations\nSET\n execution_time = ?1\nWHERE\n version = ?2\n" rows_affected=1 rows_returned=0 elapsed=9.004792ms [2023-10-23][12:19:30][INFO][defguard_client::database] Applied migrations. [2023-10-23][12:19:30][INFO][defguard_client] Database initialization completed [2023-10-23][12:19:30][INFO][defguard_client] Starting main app thread. [2023-10-23][12:19:30][DEBUG][defguard_client::database] Following locations and instances are saved. [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="SELECT id \"id?\", name, …" db.statement="\n\nSELECT\n id \"id?\",\n name,\n uuid,\n url\nFROM\n instance;\n" rows_affected=1 rows_returned=0 elapsed=90.911µs [2023-10-23][12:19:30][DEBUG][defguard_client::database] All instances found in database during start: [] [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="PRAGMA foreign_keys = ON; …" db.statement="\n\nPRAGMA foreign_keys = ON;\n" rows_affected=0 rows_returned=0 elapsed=15.86µs [2023-10-23][12:19:30][DEBUG][sqlx::query] summary="SELECT id \"id?\", instance_id, …" db.statement="\n\nSELECT\n id \"id?\",\n instance_id,\n name,\n address,\n pubkey,\n endpoint,\n allowed_ips,\n dns,\n network_id\nFROM\n location;\n" rows_affected=0 rows_returned=0 elapsed=174.688µs [2023-10-23][12:19:30][DEBUG][defguard_client::database] All locations found in database during start: [] [2023-10-23][12:19:30][INFO][defguard_client] Database info result: Ok( (), ) (defguard-client:55845): Gdk-CRITICAL **: 14:19:30.659: gdk_window_thaw_toplevel_updates: assertion 'window->update_and_descendants_freeze_count > 0' failed [2023-10-23][12:19:47][TRACE][hyper::client::pool] checkout waiting for idle connection: ("https", enrollment.teonite.net) [2023-10-23][12:19:47][DEBUG][reqwest::connect] starting new connection: https://enrollment.teonite.net/ [2023-10-23][12:19:47][TRACE][hyper::client::connect::http] Http::connect; scheme=Some("https"), host=Some("enrollment.teonite.net"), port=None [2023-10-23][12:19:47][DEBUG][hyper::client::connect::dns] resolving host="enrollment.teonite.net" [2023-10-23][12:19:48][DEBUG][hyper::client::connect::http] connecting to 185.33.37.43:443 [2023-10-23][12:19:48][DEBUG][hyper::client::connect::http] connected to 185.33.37.43:443 [2023-10-23][12:19:48][TRACE][hyper::client::conn] client handshake Http1 [2023-10-23][12:19:48][TRACE][hyper::client::client] handshake complete, spawning background dispatcher task [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Busy } [2023-10-23][12:19:48][TRACE][hyper::client::pool] checkout dropped for ("https", enrollment.teonite.net) [2023-10-23][12:19:48][TRACE][tracing::span] encode_headers; [2023-10-23][12:19:48][TRACE][tracing::span::active] -> encode_headers; [2023-10-23][12:19:48][TRACE][hyper::proto::h1::role] Client::encode method=POST, body=Some(Known(44)) [2023-10-23][12:19:48][TRACE][tracing::span::active] <- encode_headers; [2023-10-23][12:19:48][TRACE][tracing::span] -- encode_headers; [2023-10-23][12:19:48][TRACE][hyper::proto::h1::encode] sized write, len = 44 [2023-10-23][12:19:48][TRACE][hyper::proto::h1::io] buffer.flatten self.len=137 buf.len=44 [2023-10-23][12:19:48][DEBUG][hyper::proto::h1::io] flushed 181 bytes [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: KeepAlive, keep_alive: Busy } [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] Conn::read_head [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: KeepAlive, keep_alive: Busy } [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] Conn::read_head [2023-10-23][12:19:48][TRACE][hyper::proto::h1::io] received 1398 bytes [2023-10-23][12:19:48][TRACE][tracing::span] parse_headers; [2023-10-23][12:19:48][TRACE][tracing::span::active] -> parse_headers; [2023-10-23][12:19:48][TRACE][hyper::proto::h1::role] Response.parse bytes=1398 [2023-10-23][12:19:48][TRACE][hyper::proto::h1::role] Response.parse Complete(258) [2023-10-23][12:19:48][TRACE][tracing::span::active] <- parse_headers; [2023-10-23][12:19:48][TRACE][tracing::span] -- parse_headers; [2023-10-23][12:19:48][DEBUG][hyper::proto::h1::io] parsed 4 headers [2023-10-23][12:19:48][DEBUG][hyper::proto::h1::conn] incoming body is content-length (3267 bytes) [2023-10-23][12:19:48][TRACE][hyper::proto::h1::decode] decode; state=Length(3267) [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Body(Length(2127)), writing: KeepAlive, keep_alive: Busy } [2023-10-23][12:19:48][TRACE][hyper::proto::h1::decode] decode; state=Length(2127) [2023-10-23][12:19:48][TRACE][hyper::proto::h1::io] received 1398 bytes [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Body(Length(729)), writing: KeepAlive, keep_alive: Busy } [2023-10-23][12:19:48][TRACE][hyper::proto::h1::decode] decode; state=Length(729) [2023-10-23][12:19:48][TRACE][hyper::proto::h1::io] received 729 bytes [2023-10-23][12:19:48][DEBUG][hyper::proto::h1::conn] incoming body completed [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] maybe_notify; read_from_io blocked [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle } [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle } [2023-10-23][12:19:48][TRACE][hyper::client::pool] put; add idle connection for ("https", enrollment.teonite.net) [2023-10-23][12:19:48][DEBUG][hyper::client::pool] pooling idle connection for ("https", enrollment.teonite.net) [2023-10-23][12:19:48][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle } [2023-10-23][12:19:48][TRACE][hyper::client::pool] idle interval checking for expired [2023-10-23][12:19:48][DEBUG][defguard_client::commands] Retrieving all instances. [2023-10-23][12:19:48][DEBUG][sqlx::query] summary="SELECT id \"id?\", name, …" db.statement="\n\nSELECT\n id \"id?\",\n name,\n uuid,\n url\nFROM\n instance;\n" rows_affected=1 rows_returned=0 elapsed=76.744µs [2023-10-23][12:19:48][DEBUG][defguard_client::commands] Found following instances: [] [2023-10-23][12:19:48][INFO][defguard_client::commands] Returning following instances: [] [2023-10-23][12:19:56][TRACE][hyper::client::pool] take? ("https", enrollment.teonite.net): expiration = Some(90s) [2023-10-23][12:19:56][DEBUG][hyper::client::pool] reuse idle connection for ("https", enrollment.teonite.net) [2023-10-23][12:19:56][TRACE][tracing::span] encode_headers; [2023-10-23][12:19:56][TRACE][tracing::span::active] -> encode_headers; [2023-10-23][12:19:56][TRACE][hyper::proto::h1::role] Client::encode method=POST, body=Some(Known(78)) [2023-10-23][12:19:56][TRACE][tracing::span::active] <- encode_headers; [2023-10-23][12:19:56][TRACE][tracing::span] -- encode_headers; [2023-10-23][12:19:56][TRACE][hyper::proto::h1::encode] sized write, len = 78 [2023-10-23][12:19:56][TRACE][hyper::proto::h1::io] buffer.flatten self.len=289 buf.len=78 [2023-10-23][12:19:56][DEBUG][hyper::proto::h1::io] flushed 367 bytes [2023-10-23][12:19:56][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: KeepAlive, keep_alive: Busy } [2023-10-23][12:19:56][TRACE][hyper::proto::h1::conn] Conn::read_head [2023-10-23][12:19:56][TRACE][hyper::proto::h1::io] received 1332 bytes [2023-10-23][12:19:56][TRACE][tracing::span] parse_headers; [2023-10-23][12:19:56][TRACE][tracing::span::active] -> parse_headers; [2023-10-23][12:19:56][TRACE][hyper::proto::h1::role] Response.parse bytes=1332 [2023-10-23][12:19:56][TRACE][hyper::proto::h1::role] Response.parse Complete(110) [2023-10-23][12:19:56][TRACE][tracing::span::active] <- parse_headers; [2023-10-23][12:19:56][TRACE][tracing::span] -- parse_headers; [2023-10-23][12:19:56][DEBUG][hyper::proto::h1::io] parsed 3 headers [2023-10-23][12:19:56][DEBUG][hyper::proto::h1::conn] incoming body is content-length (1222 bytes) [2023-10-23][12:19:56][TRACE][hyper::proto::h1::decode] decode; state=Length(1222) [2023-10-23][12:19:56][DEBUG][hyper::proto::h1::conn] incoming body completed [2023-10-23][12:19:56][TRACE][hyper::proto::h1::conn] maybe_notify; read_from_io blocked [2023-10-23][12:19:56][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle } [2023-10-23][12:19:56][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle } [2023-10-23][12:19:56][TRACE][hyper::client::pool] put; add idle connection for ("https", enrollment.teonite.net) [2023-10-23][12:19:56][DEBUG][hyper::client::pool] pooling idle connection for ("https", enrollment.teonite.net) [2023-10-23][12:19:56][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle } [2023-10-23][12:19:56][DEBUG][defguard_client::commands] Received device configuration: CreateDeviceResponse { instance: InstanceResponse { id: "c4c61dc5-0744-45ea-afa2-637b6f695f6f", name: "Defguard", url: "XXXXXX", }, configs: [ DeviceConfig { network_id: 2, network_name: XXXXX dns: Some( "1.1.1.1", ), }, DeviceConfig { network_id: 1, network_name: "Szczecin", config: "XXXXXXX1", assigned_ip: "10.6.0.9", pubkey: "XXXXXX=", allowed_ips: "xxxx", dns: Some( "10.4.0.1", ), }, ], device: Device { id: 110, name: "ScreenShare", pubkey: "XXXXXXX", user_id: 3, created_at: 1698063596, }, } [2023-10-23][12:19:56][DEBUG][sqlx::query] summary="INSERT INTO instance (name, …" db.statement="\n\nINSERT INTO\n instance (name, uuid, url)\nVALUES\n ($1, $2, $3) RETURNING id;\n" rows_affected=1 rows_returned=1 elapsed=274.705µs [2023-10-23][12:19:56][DEBUG][sqlx::query] summary="INSERT INTO wireguard_keys (instance_id, …" db.statement="\n\nINSERT INTO\n wireguard_keys (instance_id, pubkey, prvkey)\nVALUES\n ($1, $2, $3) RETURNING id;\n" rows_affected=1 rows_returned=1 elapsed=68.699µs [2023-10-23][12:19:56][DEBUG][sqlx::query] summary="INSERT INTO location (instance_id, …" db.statement="\n\nINSERT INTO\n location (\n instance_id,\n name,\n address,\n pubkey,\n endpoint,\n allowed_ips,\n dns,\n network_id\n )\nVALUES\n ($1, $2, $3, $4, $5, $6, $7, $8) RETURNING id;\n" rows_affected=1 rows_returned=1 elapsed=66.955µs [2023-10-23][12:19:56][DEBUG][sqlx::query] summary="INSERT INTO location (instance_id, …" db.statement="\n\nINSERT INTO\n location (\n instance_id,\n name,\n address,\n pubkey,\n endpoint,\n allowed_ips,\n dns,\n network_id\n )\nVALUES\n ($1, $2, $3, $4, $5, $6, $7, $8) RETURNING id;\n" rows_affected=1 rows_returned=1 elapsed=17.282µs [2023-10-23][12:19:56][INFO][defguard_client::commands] Instance created. [2023-10-23][12:19:56][DEBUG][defguard_client::commands] Created following instance: Instance { id: Some( 1, ), name: "Defguard", uuid: "XXXXX", url: "https://XXXX", } [2023-10-23][12:19:56][DEBUG][sqlx::query] summary="SELECT id \"id?\", instance_id, …" db.statement="\n\nSELECT\n id \"id?\",\n instance_id,\n name,\n address,\n pubkey,\n endpoint,\n allowed_ips,\n dns,\n network_id\nFROM\n location\nWHERE\n instance_id = $1;\n" rows_affected=1 rows_returned=2 elapsed=283.902µs [2023-10-23][12:19:56][DEBUG][defguard_client::commands] Created following locations: [ Location { id: Some( 1, ), instance_id: 1, network_id: 2, name: "XXXX", address: "10.6.1.15", pubkey: "XXXX", endpoint: "XXXX", allowed_ips: "0.0.0.0/0", dns: Some( "1.1.1.1", ), }, Location { id: Some( 2, ), instance_id: 1, network_id: 1, name: "XXXX", address: "10.6.0.9", pubkey: "XXXXX", endpoint: "XXXXXX", allowed_ips: "XXXXXXX", dns: Some( "10.4.0.1", ), }, ] [2023-10-23][12:19:56][INFO][$D@tauri://localhost/assets/index-f1f5e17a.js:48:6249] Config saved [2023-10-23][12:20:26][TRACE][hyper::proto::h1::io] received 0 bytes [2023-10-23][12:20:26][TRACE][hyper::proto::h1::conn] found EOF on idle connection, closing [2023-10-23][12:20:26][TRACE][hyper::proto::h1::conn] State::close_read() [2023-10-23][12:20:26][TRACE][hyper::proto::h1::conn] flushed({role=client}): State { reading: Closed, writing: Init, keep_alive: Disabled } [2023-10-23][12:20:26][TRACE][hyper::proto::h1::conn] shut down IO complete [2023-10-23][12:21:18][TRACE][hyper::client::pool] idle interval checking for expired [2023-10-23][12:21:18][TRACE][hyper::client::pool] idle interval evicting closed for ("https", enrollment.teonite.net)
Asset client not found; fallback to client.html
client