Jul 17 19:13:15 (1689613995.354947) danted[801]: debug: rule_inheritoruse(): to-rule after: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:15 (1689613995.354961) danted[801]: debug: bindexternaladdr(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.117.65.55.443, authmethod 0
Jul 17 19:13:15 (1689613995.354915) danted[851]: debug: postconfigloadinit(): I am a request-child
Jul 17 19:13:15 (1689613995.354968) danted[801]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.117.65.55.443, authmethod 0
Jul 17 19:13:15 (1689613995.354973) danted[801]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:15 (1689613995.354981) danted[801]: debug: getoutaddr(): client 172.18.0.1.50731, cmd connect, reqhost 34.117.65.55.443, external.rotation = none
Jul 17 19:13:15 (1689613995.354987) danted[801]: debug: getdefaultexternal(): looking for an IPv4 address with scopeid 0/global, ifindex 0
Jul 17 19:13:15 (1689613995.354994) danted[851]: debug: sockd_setcpusettings(): old cpu scheduling policy/priority: other/0, new: other/0
Jul 17 19:13:15 (1689613995.355014) danted[851]: debug: request_postconfigload()
Jul 17 19:13:15 (1689613995.355097) danted[792]: debug: calling select().  Free negc: 96, reqc: 16, ioc: 63
Jul 17 19:13:15 (1689613995.355158) danted[851]: debug: addchild(): I am a new request-child with data-pipe 0 and ack-pipe 7
Jul 17 19:13:15 (1689613995.355168) danted[801]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:15 (1689613995.355179) danted[801]: debug: getdefaultexternal(): matched IPv4 address 10.5.0.2.0
Jul 17 19:13:15 (1689613995.355185) danted[801]: debug: addrindex_on_externallist(): checking if address 10.5.0.2.0 is a configured external address
Jul 17 19:13:15 (1689613995.355194) danted[801]: debug: addrindex_on_externallist(): external address #0: interfacename nordlynx
Jul 17 19:13:15 (1689613995.355238) danted[835]: debug: run_negotiate(): mother telling us to exit normally when done
Jul 17 19:13:15 (1689613995.355258) danted[835]: debug: sockdexit(): insignal = 0
Jul 17 19:13:15 (1689613995.355265) danted[835]: debug: negotiate-child: shutting down
Jul 17 19:13:15 (1689613995.355264) danted[801]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:15 (1689613995.355272) danted[851]: debug: sockd_print_child_ready_message(): I'm request-child and ready to serve with 1048567 free fds and 1 free slot
Jul 17 19:13:15 (1689613995.355279) danted[801]: debug: getoutaddr(): local address 10.5.0.2 selected for forwarding from client 172.18.0.1.50731 to 34.117.65.55.443
Jul 17 19:13:15 (1689613995.355298) danted[801]: debug: socks_bind(): trying to bind address 10.5.0.2.50731 on fd 10.  Retries is 0
Jul 17 19:13:15 (1689613995.355312) danted[801]: debug: socks_bind(): bound address 10.5.0.2.50731 on fd 10
Jul 17 19:13:15 (1689613995.355316) danted[801]: debug: bindexternaladdr(): bound address on external side is 10.5.0.2.50731
Jul 17 19:13:15 (1689613995.355321) danted[801]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:15 (1689613995.355329) danted[801]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:15 (1689613995.355336) danted[801]: debug: setsockoptions(): fd 10, type = 1, isclientside = 0
Jul 17 19:13:15 (1689613995.355341) danted[801]: debug: setsockoptions(): 3 options to set
Jul 17 19:13:15 (1689613995.355350) danted[801]: debug: setnonblocking(): fd 10: setsockoptions()
Jul 17 19:13:15 (1689613995.355354) danted[801]: debug: setsockoptions(): buffer sizes for fd 10 are: SO_SNDBUF: 16384, SO_RCVBUF: 87380
Jul 17 19:13:15 (1689613995.355357) danted[801]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 10 (in: 8) on the external side
Jul 17 19:13:15 (1689613995.355360) danted[801]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 5 (pre-establishment or any time)
Jul 17 19:13:15 (1689613995.355363) danted[801]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 5
Jul 17 19:13:15 (1689613995.355372) danted[801]: debug: serverchain(): client 172.18.0.1.50731, auth none, request VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.117.65.55.443
Jul 17 19:13:15 (1689613995.355378) danted[801]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.117.65.55.443, authmethod 0
Jul 17 19:13:15 (1689613995.355381) danted[801]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:15 (1689613995.355382) danted[801]: debug: serverchain(): using direct system calls for fd 10
Jul 17 19:13:15 (1689613995.355435) danted[801]: debug: socks_connecthost(): connect to 34.117.65.55.443 on external/target side from 10.5.0.2.50731, fd 10.  Timeout is 0
Jul 17 19:13:15 (1689613995.355582) danted[801]: debug: socks_connecthost(): connect(2) to 34.117.65.55.443 from 10.5.0.2.50731 on fd 10 returned -1 (Operation now in progress)
Jul 17 19:13:15 (1689613995.355590) danted[801]: debug: socks_connecthost(): connect to 34.117.65.55.443 from 10.5.0.2.50731 on fd 10 in progress (Operation now in progress)
Jul 17 19:13:15 (1689613995.355594) danted[801]: debug: connect to host 34.117.65.55.443 is now in progress
Jul 17 19:13:15 (1689613995.355606) danted[801]: debug: flushio(): io->control.s = fd -1, io->src.s = fd 8, io->dst.s = fd 10
Jul 17 19:13:15 (1689613995.355613) danted[801]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:15 (1689613995.355618) danted[801]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:15 (1689613995.355697) danted[801]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:15 (1689613995.355951) danted[792]: debug: sockd_pushsignal(): pushed signal 17 from pid 835.  Number of signals on the stack is now 1
Jul 17 19:13:15 (1689613995.355964) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:15 (1689613995.355976) danted[792]: debug: sockd_handledsignals(): signals left on the stack after popping signal 17: 0
Jul 17 19:13:15 (1689613995.355981) danted[792]: debug: SIGCHLD [: processing signal 17
Jul 17 19:13:15 (1689613995.356026) danted[792]: debug: sigchld(): process 835 exited
Jul 17 19:13:15 (1689613995.356033) danted[792]: debug: sigchld(): negotiate-child-child 835 exiting after 78s and 1 client
Jul 17 19:13:15 (1689613995.356038) danted[792]: debug: resource usage for negotiate-child-child 835
Jul 17 19:13:15 (1689613995.356044) danted[792]: debug: removechild(): pid = 835
Jul 17 19:13:15 (1689613995.356049) danted[792]: debug: SIGCHLD ]: finished processing signal 17
Jul 17 19:13:15 (1689613995.356101) danted[792]: debug: calling select().  Free negc: 96, reqc: 16, ioc: 63
Jul 17 19:13:15 (1689613995.356123) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:15 (1689613995.356129) danted[792]: debug: trying to receive request from request-child 801
Jul 17 19:13:15 (1689613995.356147) danted[792]: debug: recv_io(): we are mother
Jul 17 19:13:15 (1689613995.356280) danted[792]: debug: sending client 172.18.0.1.50731 to io-child (pid 828 with 31 slots free)
Jul 17 19:13:15 (1689613995.356286) danted[792]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:15 (1689613995.356291) danted[792]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:15 (1689613995.356335) danted[792]: debug: handlechildcommand(): command 1 from request-child 801
Jul 17 19:13:15 (1689613995.356340) danted[792]: debug: handlechildcommand(): request-child 801 has freed a TCP slot, now has 1 slot free
Jul 17 19:13:15 (1689613995.356348) danted[792]: debug: childcheck(): counted 16 free request-child slots.  Removing pid 801 which has handled 1 client during 84s
Jul 17 19:13:15 (1689613995.356351) danted[792]: debug: closechild(): pid = 801, isnormalexit = 1
Jul 17 19:13:15 (1689613995.356432) danted[792]: debug: calling select().  Free negc: 96, reqc: 16, ioc: 62
Jul 17 19:13:15 (1689613995.356439) danted[801]: debug: run_request(): mother telling us to exit normally when done
Jul 17 19:13:15 (1689613995.356459) danted[801]: debug: sockdexit(): insignal = 0
Jul 17 19:13:15 (1689613995.356465) danted[801]: debug: request-child: shutting down
Jul 17 19:13:15 (1689613995.356502) danted[828]: debug: recv_io(): we are child
Jul 17 19:13:15 (1689613995.356565) danted[828]: debug: socks_allocbuffer(): fd 10, stype = 1
Jul 17 19:13:15 (1689613995.356627) danted[828]: debug: socks_allocbuffer(): fd 11, stype = 1
Jul 17 19:13:15 (1689613995.356671) danted[828]: debug: recv_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:15 (1689613995.356677) danted[828]: debug: recv_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:15 (1689613995.356681) danted[828]: debug: io_updatemonitor(): control-fd -1, src-fd 10, dst-fd 11, protocol tcp, command connect, mstats_shmid 0, at address (nil)
Jul 17 19:13:15 (1689613995.356693) danted[828]: debug: monitormatch(): 172.18.0.1.50731 -> 34.117.65.55.443
Jul 17 19:13:15 (1689613995.356696) danted[828]: debug: io_updatemonitor(): previously matched mstats_shmid 0, now matching monitor #0 with mstats_shmid 0 (same as now) and alarmsconfigured = 0
Jul 17 19:13:15 (1689613995.356699) danted[828]: debug: recv_io(): we are child
Jul 17 19:13:15 (1689613995.356710) danted[828]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:15 (1689613995.356714) danted[828]: debug: getnewios(): received 1 new io, errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:15 (1689613995.356942) danted[828]: debug: io_fillset_connectinprogress(): fd 11 marked as still connecting
Jul 17 19:13:15 (1689613995.356953) danted[828]: debug: io_fillset_connectinprogress(): fd 13 marked as still connecting
Jul 17 19:13:15 (1689613995.356958) danted[828]: debug: run_io(): first select; readable/connected?
Jul 17 19:13:15 (1689613995.356962) danted[828]: debug: io_gettimeout(): last_time = 419980, tnow = 419989, last_timeout_isset = 1, last_timeout = 8.999999
Jul 17 19:13:15 (1689613995.356967) danted[828]: debug: io_gettimeout(): timeout for iov #0 is in 30s
Jul 17 19:13:15 (1689613995.356971) danted[828]: debug: io_timeuntiltimeout(): timeouttype = 2, protocoltimeout = 30, tnow = 419989, lastio = 419958 (31s ago), timeout reached -1s ago
Jul 17 19:13:15 (1689613995.356975) danted[828]: debug: io_gettimeout(): timeout for iov #1 is in 0s
Jul 17 19:13:15 (1689613995.357275) danted[792]: debug: sockd_pushsignal(): pushed signal 17 from pid 801.  Number of signals on the stack is now 1
Jul 17 19:13:15 (1689613995.357288) danted[792]: debug: sockd_handledsignals(): signals left on the stack after popping signal 17: 0
Jul 17 19:13:15 (1689613995.357300) danted[792]: debug: SIGCHLD [: processing signal 17
Jul 17 19:13:15 (1689613995.357345) danted[792]: debug: sigchld(): process 801 exited
Jul 17 19:13:15 (1689613995.357352) danted[792]: debug: sigchld(): request-child-child 801 exiting after 84s and 1 client
Jul 17 19:13:15 (1689613995.357358) danted[792]: debug: resource usage for request-child-child 801
Jul 17 19:13:15 (1689613995.357363) danted[792]: debug: removechild(): pid = 801
Jul 17 19:13:15 (1689613995.357372) danted[792]: debug: SIGCHLD ]: finished processing signal 17
Jul 17 19:13:15 (1689613995.357397) danted[792]: debug: main(): selectn() returned -1 (Interrupted system call)
Jul 17 19:13:15 (1689613995.357464) danted[792]: debug: calling select().  Free negc: 96, reqc: 16, ioc: 62
Jul 17 19:13:16 (1689613996.099939) danted[831]: debug: io_timeuntiltimeout(): timeouttype = 2, protocoltimeout = 30, tnow = 419990, lastio = 419958 (32s ago), timeout reached -2s ago
Jul 17 19:13:16 (1689613996.099979) danted[831]: debug: io_gettimedout(): io #0 with control -1, src 10, dst 11, has reached the timeout point.  I/O last done at 419958.353840
Jul 17 19:13:16 (1689613996.099995) danted[831]: debug: send_response(): sending response: VER: 5 REP: 6 FLAG: 0 ATYP: 1 address: 0.0.0.0.0, authmethod 0
Jul 17 19:13:16 (1689613996.100164) danted[831]: debug: io_delete(): command connect, bad-fd -1, controlfd -1, src-fd 10, dst-fd 11 dstc = 0
Jul 17 19:13:16 (1689613996.100201) danted[831]: debug: io_timeuntiltimeout(): timeouttype = 2, protocoltimeout = 30, tnow = 419990, lastio = 419958 (32s ago), timeout reached -2s ago
Jul 17 19:13:16 (1689613996.100206) danted[831]: info: pass(1): tcp/connect ]: 0 -> 172.18.0.1.50524 172.18.0.4.1080 -> 0, 0 -> 10.5.0.2.50524 172.64.163.15.443 -> 0: connect timeout.  Session duration: 32s
Jul 17 19:13:16 (1689613996.100217) danted[831]: debug: io_timeuntiltimeout(): timeouttype = 2, protocoltimeout = 30, tnow = 419990, lastio = 419958 (32s ago), timeout reached -2s ago
Jul 17 19:13:16 (1689613996.100220) danted[831]: info: pass(2): tcp/accept ]: 0 -> 172.18.0.1.50524 172.18.0.4.1080 -> 0: connect timeout.  Session duration: 32s
Jul 17 19:13:16 (1689613996.100223) danted[831]: debug: socks_freebuffer(): fd 10
Jul 17 19:13:16 (1689613996.100225) danted[831]: debug: socks_freebuffer(): fd 11
Jul 17 19:13:16 (1689613996.100650) danted[831]: debug: io_delete(): before SHMEM_UNUSE(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.100672) danted[831]: debug: io_delete(): before SHMEM_UNUSE(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.100710) danted[795]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.100785) danted[795]: debug: handlechildcommand(): command 1 from io-child 831
Jul 17 19:13:16 (1689613996.100790) danted[795]: debug: handlechildcommand(): io-child 831 has freed a TCP slot, now has 31 slots free
Jul 17 19:13:16 (1689613996.100858) danted[795]: debug: calling select().  Free negc: 96, reqc: 16, ioc: 63
Jul 17 19:13:16 (1689613996.101131) danted[831]: debug: io_fillset_connectinprogress(): fd 13 marked as still connecting
Jul 17 19:13:16 (1689613996.101150) danted[831]: debug: run_io(): first select; readable/connected?
Jul 17 19:13:16 (1689613996.101155) danted[831]: debug: io_gettimeout(): last_time = 419989, tnow = 419990, last_timeout_isset = 1, last_timeout = 0.999999
Jul 17 19:13:16 (1689613996.101161) danted[831]: debug: io_gettimeout(): timeout for iov #1 is in 29s
Jul 17 19:13:16 (1689613996.139929) danted[795]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.139981) danted[795]: debug: accepted tcp client 172.18.0.1.50732 on address 172.18.0.4.1080, fd 7
Jul 17 19:13:16 (1689613996.139987) danted[795]: debug: sending client 172.18.0.1.50732 to negotiate-child (pid 848 with 96 slots free)
Jul 17 19:13:16 (1689613996.139991) danted[795]: debug: send_client(): buflen = 0
Jul 17 19:13:16 (1689613996.140044) danted[795]: debug: childcheck(): current # of free negotiate-child slots is 95, configured minimum is 96: need to add more negotiate-children
Jul 17 19:13:16 (1689613996.140050) danted[795]: debug: addchild(): type is negotiate-child
Jul 17 19:13:16 (1689613996.140066) danted[795]: debug: setnonblocking(): fd 23: pipe between moter and child
Jul 17 19:13:16 (1689613996.140071) danted[795]: debug: setnonblocking(): fd 55: pipe between moter and child
Jul 17 19:13:16 (1689613996.140073) danted[795]: debug: setnonblocking(): fd 20: pipe between moter and child
Jul 17 19:13:16 (1689613996.140076) danted[795]: debug: setnonblocking(): fd 21: pipe between moter and child
Jul 17 19:13:16 (1689613996.140079) danted[795]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:16 (1689613996.140099) danted[795]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:16 (1689613996.140113) danted[795]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:16 (1689613996.140117) danted[795]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:16 (1689613996.140124) danted[795]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:16 (1689613996.140126) danted[795]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:16 (1689613996.140133) danted[795]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:16 (1689613996.140136) danted[795]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:16 (1689613996.140141) danted[795]: debug: addchild(): highest fd in use at the moment: 60
Jul 17 19:13:16 (1689613996.140386) danted[848]: debug: rulespermit(): 172.18.0.1.50732 -> 172.18.0.4.1080, clientauth N/A, srcauth notset, command accept, fd 8 from 172.18.0.1.50732, accepted on 172.18.0.4.1080
Jul 17 19:13:16 (1689613996.140502) danted[848]: debug: rulespermit(): trying to match against client-rule-rule #1, verdict = pass
Jul 17 19:13:16 (1689613996.140540) danted[848]: debug: addrmatch(): matching ruleaddress IPv4 address 10.0.0.0/8 against IPv4 address 172.18.0.1.50732 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.140545) danted[848]: debug: rulespermit(): trying to match against client-rule-rule #2, verdict = pass
Jul 17 19:13:16 (1689613996.140551) danted[848]: debug: addrmatch(): matching ruleaddress IPv4 address 172.16.0.0/12 against IPv4 address 172.18.0.1.50732 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.140561) danted[848]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 172.18.0.4.1080 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.140574) danted[848]: debug: methodisset(): checking if method notset is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.140581) danted[848]: debug: rulespermit(): changing authmethod from -1 to 0
Jul 17 19:13:16 (1689613996.140585) danted[848]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.140592) danted[848]: debug: accesscheck(): method: none, 172.18.0.1.50732 -> 172.18.0.4.1080 
Jul 17 19:13:16 (1689613996.140594) danted[848]: debug: methodisset(): checking if method none is set in the list (0) ""
Jul 17 19:13:16 (1689613996.140597) danted[848]: debug: methodisset(): checking if method none is set in the list (0) ""
Jul 17 19:13:16 (1689613996.140599) danted[848]: debug: accesscheck(): authentication matched
Jul 17 19:13:16 (1689613996.140608) danted[848]: debug: rulespermit(): rule matched: 2 (client-rule), verdict pass
Jul 17 19:13:16 (1689613996.140616) danted[848]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:16 (1689613996.140625) danted[848]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 6 (post-establishment or any time)
Jul 17 19:13:16 (1689613996.140628) danted[848]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:16 (1689613996.140645) danted[848]: debug: shmem_userule(): cinfo: 172.18.0.1.50732
Jul 17 19:13:16 (1689613996.140650) danted[848]: debug: shmem_userule(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.140675) danted[848]: info: pass(2): tcp/accept [: 172.18.0.1.50732 172.18.0.4.1080
Jul 17 19:13:16 (1689613996.140680) danted[848]: debug: socks_allocbuffer(): fd 8, stype = 1
Jul 17 19:13:16 (1689613996.140737) danted[795]: debug: addchild(): created new negotiate-child with pid 852, data-pipe 20 and ack-pipe 23.  Minimum rcvbuf: 24536, set: 49072 and 49072.  Minimum sndbuf: 2355456, set: 4710912 and 4710912
Jul 17 19:13:16 (1689613996.140757) danted[795]: debug: childcheck(): added child, pid 852
Jul 17 19:13:16 (1689613996.140930) danted[848]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:16 (1689613996.140958) danted[795]: debug: calling select().  Free negc: 191, reqc: 16, ioc: 63
Jul 17 19:13:16 (1689613996.140967) danted[848]: debug: recv_negotiate(): recvmsg() from mother returned -1 after having received 1 new clients (0 failed/blocked clients).  errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:16 (1689613996.141144) danted[848]: debug: recv_clientrequest(): fd 8, client 172.18.0.1.50732, state->complete: 0, read so far: 0
Jul 17 19:13:16 (1689613996.141213) danted[848]: debug: recv_clientrequest(): initiating negotiation with client at 172.18.0.1.50732 which connected to us on 172.18.0.4.1080
Jul 17 19:13:16 (1689613996.141239) danted[848]: debug: recv_methods(): client 172.18.0.1.50732 offered 1 authentication method: 0x0 (none)
Jul 17 19:13:16 (1689613996.141245) danted[848]: debug: recv_methods(): socksmethod to use not set, selecting amongst the following 1 method: none
Jul 17 19:13:16 (1689613996.141249) danted[848]: debug: recv_methods(): sending authentication reply: VER: 5 METHOD: 0 (none)
Jul 17 19:13:16 (1689613996.141373) danted[848]: debug: run_negotiate(): recv_clientrequest() from client 172.18.0.1.50732 returned 2, errno is 0 (no error)
Jul 17 19:13:16 (1689613996.141701) danted[852]: debug: postconfigloadinit(): I am a negotiate-child
Jul 17 19:13:16 (1689613996.141998) danted[852]: debug: sockd_setcpusettings(): old cpu scheduling policy/priority: other/0, new: other/0
Jul 17 19:13:16 (1689613996.142074) danted[848]: debug: recv_clientrequest(): fd 8, client 172.18.0.1.50732, state->complete: 0, read so far: 3
Jul 17 19:13:16 (1689613996.142116) danted[848]: debug: run_negotiate(): recv_clientrequest() from client 172.18.0.1.50732 returned 3, errno is 0 (no error)
Jul 17 19:13:16 (1689613996.142123) danted[848]: debug: send_negotiate(): no shmem to unuse/clear
Jul 17 19:13:16 (1689613996.142140) danted[848]: debug: send_negotiate(): client 172.18.0.1.50732 finished negotiate phase for command connect using proxyprotocol socks_v5
Jul 17 19:13:16 (1689613996.142176) danted[848]: debug: delete_negotiate(): forwardedtomother: 1
Jul 17 19:13:16 (1689613996.142182) danted[848]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:16 (1689613996.142340) danted[795]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.142355) danted[795]: debug: trying to receive request from negotiate-child 848
Jul 17 19:13:16 (1689613996.142489) danted[795]: debug: sending client 172.18.0.1.50732 to request-child (pid 803 with 1 slots free)
Jul 17 19:13:16 (1689613996.142519) danted[795]: debug: handlechildcommand(): command 1 from negotiate-child 848
Jul 17 19:13:16 (1689613996.142524) danted[795]: debug: handlechildcommand(): negotiate-child 848 has freed a TCP slot, now has 96 slots free
Jul 17 19:13:16 (1689613996.142566) danted[795]: debug: childcheck(): current # of free request-child slots is 15, configured minimum is 16: need to add more request-children
Jul 17 19:13:16 (1689613996.142571) danted[795]: debug: addchild(): type is request-child
Jul 17 19:13:16 (1689613996.142588) danted[795]: debug: setnonblocking(): fd 58: pipe between moter and child
Jul 17 19:13:16 (1689613996.142592) danted[795]: debug: setnonblocking(): fd 60: pipe between moter and child
Jul 17 19:13:16 (1689613996.142594) danted[795]: debug: setnonblocking(): fd 21: pipe between moter and child
Jul 17 19:13:16 (1689613996.142596) danted[795]: debug: setnonblocking(): fd 55: pipe between moter and child
Jul 17 19:13:16 (1689613996.142599) danted[795]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:16 (1689613996.142608) danted[795]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:16 (1689613996.142627) danted[795]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:16 (1689613996.142631) danted[795]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:16 (1689613996.142638) danted[795]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:16 (1689613996.142640) danted[795]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:16 (1689613996.142647) danted[795]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:16 (1689613996.142650) danted[795]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:16 (1689613996.142655) danted[795]: debug: addchild(): highest fd in use at the moment: 60
Jul 17 19:13:16 (1689613996.142843) danted[852]: debug: negotiate_postconfigload()
Jul 17 19:13:16 (1689613996.142812) danted[803]: debug: dorequest(): command 1 request received from client 172.18.0.1.50732.  Accepted on 172.18.0.4.1080, matched by client-rule #2, auth: none.  Packet: VER: 5 CMD: 1 FLAG: 0 ATYP: 3 address: firefox.settings.services.mozilla.com.443 
Jul 17 19:13:16 (1689613996.142884) danted[803]: debug: socks_allocbuffer(): fd 8, stype = 1
Jul 17 19:13:16 (1689613996.143156) danted[803]: debug: reqhostisok(): host firefox.settings.services.mozilla.com.443, command connect
Jul 17 19:13:16 (1689613996.143199) danted[803]: debug: set_hints_ai_family: ai_family = 2
Jul 17 19:13:16 (1689613996.143213) danted[803]: debug: cgetaddrinfo(), hit: 0, miss: 0
Jul 17 19:13:16 (1689613996.143241) danted[795]: debug: addchild(): created new request-child with pid 853, data-pipe 21 and ack-pipe 58.  Minimum rcvbuf: 39160, set: 78320 and 78320.  Minimum sndbuf: 39160, set: 78320 and 78320
Jul 17 19:13:16 (1689613996.143259) danted[795]: debug: childcheck(): added child, pid 853
Jul 17 19:13:16 (1689613996.143381) danted[853]: debug: postconfigloadinit(): I am a request-child
Jul 17 19:13:16 (1689613996.143471) danted[853]: debug: sockd_setcpusettings(): old cpu scheduling policy/priority: other/0, new: other/0
Jul 17 19:13:16 (1689613996.143490) danted[853]: debug: request_postconfigload()
Jul 17 19:13:16 (1689613996.143519) danted[795]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 63
Jul 17 19:13:16 (1689613996.143609) danted[853]: debug: addchild(): I am a new request-child with data-pipe 0 and ack-pipe 7
Jul 17 19:13:16 (1689613996.143684) danted[853]: debug: sockd_print_child_ready_message(): I'm request-child and ready to serve with 1048567 free fds and 1 free slot
Jul 17 19:13:16 (1689613996.143990) danted[852]: debug: addchild(): I am a new negotiate-child with data-pipe 0 and ack-pipe 7
Jul 17 19:13:16 (1689613996.144378) danted[852]: debug: sockd_print_child_ready_message(): I'm negotiate-child and ready to serve with 1048567 free fds and 96 free slots
Jul 17 19:13:16 (1689613996.157573) danted[803]: debug: cgetaddrinfo(): getaddrinfo(firefox.settings.services.mozilla.com, <NULL>, { ai_flags: 0, ai_family: 2, ai_socktype: 0, ai_protocol: 0 }) returned 0 and 0x7ffa09662910: no error
Jul 17 19:13:16 (1689613996.157679) danted[803]: debug: addrinfocopy(): skipping address 34.149.100.209.0, protocol 17
Jul 17 19:13:16 (1689613996.157698) danted[803]: debug: addrinfocopy(): skipping address family 2
Jul 17 19:13:16 (1689613996.157700) danted[803]: debug: addrinfocopy(): skipping address family 2
Jul 17 19:13:16 (1689613996.157715) danted[803]: debug: reqhostisok(): hostname firefox.settings.services.mozilla.com.443 in connect-request resolved to address 34.149.100.209.443
Jul 17 19:13:16 (1689613996.157737) danted[803]: debug: rulespermit(): 172.18.0.1.50732 -> firefox.settings.services.mozilla.com.443, clientauth none, srcauth none, command connect, fd 8 from 172.18.0.1.50732, accepted on 172.18.0.4.1080
Jul 17 19:13:16 (1689613996.158542) danted[803]: debug: rulespermit(): trying to match against socks-rule-rule #1, verdict = pass
Jul 17 19:13:16 (1689613996.158574) danted[803]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 172.18.0.1.50732 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.158587) danted[803]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against host/domain-name firefox.settings.services.mozilla.com.443 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.171842) danted[803]: debug: cgetaddrinfo(): getaddrinfo(firefox.settings.services.mozilla.com, <NULL>, { ai_flags: 0, ai_family: 0, ai_socktype: 0, ai_protocol: 0 }) returned 0 and 0x7ffa096629b0: no error
Jul 17 19:13:16 (1689613996.171886) danted[803]: debug: addrinfocopy(): skipping address 34.149.100.209.0, protocol 17
Jul 17 19:13:16 (1689613996.171891) danted[803]: debug: addrinfocopy(): skipping address family 2
Jul 17 19:13:16 (1689613996.171892) danted[803]: debug: addrinfocopy(): skipping address family 2
Jul 17 19:13:16 (1689613996.171903) danted[803]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.171908) danted[803]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.171911) danted[803]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.171921) danted[803]: debug: accesscheck(): method: none, 172.18.0.1.50732 -> 172.18.0.4.1080 
Jul 17 19:13:16 (1689613996.171924) danted[803]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.171927) danted[803]: debug: accesscheck(): method none already checked, matches
Jul 17 19:13:16 (1689613996.171935) danted[803]: debug: rulespermit(): rule matched: 1 (socks-rule), verdict pass
Jul 17 19:13:16 (1689613996.171949) danted[803]: debug: dorequest(): client requested target firefox.settings.services.mozilla.com.443, we will use 34.149.100.209.443
Jul 17 19:13:16 (1689613996.171967) danted[803]: debug: rule_inheritoruse(): from-rule before (cinfo: 172.18.0.1.50732): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.171976) danted[803]: debug: rule_inheritoruse(): to-rule before (cinfo: 172.18.0.1.50732): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.171981) danted[803]: debug: rule_inheritoruse(): no session settings in client-rule #2 to consider for inheritance
Jul 17 19:13:16 (1689613996.171984) danted[803]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:16 (1689613996.171986) danted[803]: debug: rule_inheritoruse(): no bandwidth settings in client-rule #2 to consider for inheritance
Jul 17 19:13:16 (1689613996.171988) danted[803]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:16 (1689613996.171991) danted[803]: debug: alarm_inherit: sidesconnected: 1
Jul 17 19:13:16 (1689613996.171995) danted[803]: debug: alarm_inherit: from-rule: shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.171998) danted[803]: debug: alarm_inherit: to-rule: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.172001) danted[803]: debug: rule_inheritoruse(): no mstats settings in client-rule #2 to consider for inheritance
Jul 17 19:13:16 (1689613996.172003) danted[803]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:16 (1689613996.172005) danted[803]: debug: rule_inheritoruse(): from-rule after: shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.172008) danted[803]: debug: rule_inheritoruse(): to-rule after: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.172021) danted[803]: debug: bindexternaladdr(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.149.100.209.443, authmethod 0
Jul 17 19:13:16 (1689613996.172027) danted[803]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.149.100.209.443, authmethod 0
Jul 17 19:13:16 (1689613996.172029) danted[803]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:16 (1689613996.172037) danted[803]: debug: getoutaddr(): client 172.18.0.1.50732, cmd connect, reqhost 34.149.100.209.443, external.rotation = none
Jul 17 19:13:16 (1689613996.172044) danted[803]: debug: getdefaultexternal(): looking for an IPv4 address with scopeid 0/global, ifindex 0
Jul 17 19:13:16 (1689613996.172189) danted[803]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:16 (1689613996.172198) danted[803]: debug: getdefaultexternal(): matched IPv4 address 10.5.0.2.0
Jul 17 19:13:16 (1689613996.172206) danted[803]: debug: addrindex_on_externallist(): checking if address 10.5.0.2.0 is a configured external address
Jul 17 19:13:16 (1689613996.172213) danted[803]: debug: addrindex_on_externallist(): external address #0: interfacename nordlynx
Jul 17 19:13:16 (1689613996.172283) danted[803]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:16 (1689613996.172297) danted[803]: debug: getoutaddr(): local address 10.5.0.2 selected for forwarding from client 172.18.0.1.50732 to 34.149.100.209.443
Jul 17 19:13:16 (1689613996.172313) danted[803]: debug: socks_bind(): trying to bind address 10.5.0.2.50732 on fd 10.  Retries is 0
Jul 17 19:13:16 (1689613996.172326) danted[803]: debug: socks_bind(): bound address 10.5.0.2.50732 on fd 10
Jul 17 19:13:16 (1689613996.172330) danted[803]: debug: bindexternaladdr(): bound address on external side is 10.5.0.2.50732
Jul 17 19:13:16 (1689613996.172334) danted[803]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:16 (1689613996.172341) danted[803]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:16 (1689613996.172348) danted[803]: debug: setsockoptions(): fd 10, type = 1, isclientside = 0
Jul 17 19:13:16 (1689613996.172353) danted[803]: debug: setsockoptions(): 3 options to set
Jul 17 19:13:16 (1689613996.172361) danted[803]: debug: setnonblocking(): fd 10: setsockoptions()
Jul 17 19:13:16 (1689613996.172365) danted[803]: debug: setsockoptions(): buffer sizes for fd 10 are: SO_SNDBUF: 16384, SO_RCVBUF: 87380
Jul 17 19:13:16 (1689613996.172369) danted[803]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 10 (in: 8) on the external side
Jul 17 19:13:16 (1689613996.172372) danted[803]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 5 (pre-establishment or any time)
Jul 17 19:13:16 (1689613996.172374) danted[803]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 5
Jul 17 19:13:16 (1689613996.172381) danted[803]: debug: serverchain(): client 172.18.0.1.50732, auth none, request VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.149.100.209.443
Jul 17 19:13:16 (1689613996.172386) danted[803]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.149.100.209.443, authmethod 0
Jul 17 19:13:16 (1689613996.172389) danted[803]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:16 (1689613996.172391) danted[803]: debug: serverchain(): using direct system calls for fd 10
Jul 17 19:13:16 (1689613996.172465) danted[803]: debug: socks_connecthost(): connect to 34.149.100.209.443 on external/target side from 10.5.0.2.50732, fd 10.  Timeout is 0
Jul 17 19:13:16 (1689613996.172611) danted[803]: debug: socks_connecthost(): connect(2) to 34.149.100.209.443 from 10.5.0.2.50732 on fd 10 returned -1 (Operation now in progress)
Jul 17 19:13:16 (1689613996.172618) danted[803]: debug: socks_connecthost(): connect to 34.149.100.209.443 from 10.5.0.2.50732 on fd 10 in progress (Operation now in progress)
Jul 17 19:13:16 (1689613996.172622) danted[803]: debug: connect to host 34.149.100.209.443 is now in progress
Jul 17 19:13:16 (1689613996.172633) danted[803]: debug: flushio(): io->control.s = fd -1, io->src.s = fd 8, io->dst.s = fd 10
Jul 17 19:13:16 (1689613996.172640) danted[803]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.172645) danted[803]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.172720) danted[803]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:16 (1689613996.172839) danted[795]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.172851) danted[795]: debug: trying to receive request from request-child 803
Jul 17 19:13:16 (1689613996.172876) danted[795]: debug: recv_io(): we are mother
Jul 17 19:13:16 (1689613996.173002) danted[795]: debug: sending client 172.18.0.1.50732 to io-child (pid 831 with 31 slots free)
Jul 17 19:13:16 (1689613996.173007) danted[795]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.173012) danted[795]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.173046) danted[795]: debug: handlechildcommand(): command 1 from request-child 803
Jul 17 19:13:16 (1689613996.173050) danted[795]: debug: handlechildcommand(): request-child 803 has freed a TCP slot, now has 1 slot free
Jul 17 19:13:16 (1689613996.173067) danted[795]: debug: childcheck(): counted 16 free request-child slots.  Removing pid 803 which has handled 1 client during 85s
Jul 17 19:13:16 (1689613996.173072) danted[795]: debug: closechild(): pid = 803, isnormalexit = 1
Jul 17 19:13:16 (1689613996.173137) danted[795]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 62
Jul 17 19:13:16 (1689613996.173213) danted[803]: debug: run_request(): mother telling us to exit normally when done
Jul 17 19:13:16 (1689613996.173231) danted[803]: debug: sockdexit(): insignal = 0
Jul 17 19:13:16 (1689613996.173237) danted[803]: debug: request-child: shutting down
Jul 17 19:13:16 (1689613996.173568) danted[831]: debug: recv_io(): we are child
Jul 17 19:13:16 (1689613996.173645) danted[831]: debug: socks_allocbuffer(): fd 10, stype = 1
Jul 17 19:13:16 (1689613996.173710) danted[831]: debug: socks_allocbuffer(): fd 11, stype = 1
Jul 17 19:13:16 (1689613996.173751) danted[831]: debug: recv_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.173758) danted[831]: debug: recv_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.173764) danted[831]: debug: io_updatemonitor(): control-fd -1, src-fd 10, dst-fd 11, protocol tcp, command connect, mstats_shmid 0, at address (nil)
Jul 17 19:13:16 (1689613996.173777) danted[831]: debug: monitormatch(): 172.18.0.1.50732 -> 34.149.100.209.443
Jul 17 19:13:16 (1689613996.173780) danted[831]: debug: io_updatemonitor(): previously matched mstats_shmid 0, now matching monitor #0 with mstats_shmid 0 (same as now) and alarmsconfigured = 0
Jul 17 19:13:16 (1689613996.173784) danted[831]: debug: recv_io(): we are child
Jul 17 19:13:16 (1689613996.173796) danted[831]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:16 (1689613996.173801) danted[831]: debug: getnewios(): received 1 new io, errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:16 (1689613996.173956) danted[795]: debug: sockd_pushsignal(): pushed signal 17 from pid 803.  Number of signals on the stack is now 1
Jul 17 19:13:16 (1689613996.173979) danted[795]: debug: sockd_handledsignals(): signals left on the stack after popping signal 17: 0
Jul 17 19:13:16 (1689613996.173993) danted[795]: debug: SIGCHLD [: processing signal 17
Jul 17 19:13:16 (1689613996.174036) danted[831]: debug: io_fillset_connectinprogress(): fd 11 marked as still connecting
Jul 17 19:13:16 (1689613996.174045) danted[831]: debug: io_fillset_connectinprogress(): fd 13 marked as still connecting
Jul 17 19:13:16 (1689613996.174049) danted[831]: debug: run_io(): first select; readable/connected?
Jul 17 19:13:16 (1689613996.174048) danted[795]: debug: sigchld(): process 803 exited
Jul 17 19:13:16 (1689613996.174051) danted[831]: debug: io_gettimeout(): last_time = 419990, tnow = 419990, last_timeout_isset = 1, last_timeout = 29.999999
Jul 17 19:13:16 (1689613996.174058) danted[795]: debug: sigchld(): request-child-child 803 exiting after 85s and 1 client
Jul 17 19:13:16 (1689613996.174065) danted[795]: debug: resource usage for request-child-child 803
Jul 17 19:13:16 (1689613996.174070) danted[795]: debug: removechild(): pid = 803
Jul 17 19:13:16 (1689613996.174080) danted[795]: debug: SIGCHLD ]: finished processing signal 17
Jul 17 19:13:16 (1689613996.174105) danted[795]: debug: main(): selectn() returned -1 (Interrupted system call)
Jul 17 19:13:16 (1689613996.174162) danted[795]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 62
Jul 17 19:13:16 (1689613996.358014) danted[828]: debug: io_timeuntiltimeout(): timeouttype = 2, protocoltimeout = 30, tnow = 419990, lastio = 419958 (32s ago), timeout reached -2s ago
Jul 17 19:13:16 (1689613996.358053) danted[828]: debug: io_gettimedout(): io #1 with control -1, src 12, dst 13, has reached the timeout point.  I/O last done at 419958.592462
Jul 17 19:13:16 (1689613996.358070) danted[828]: debug: send_response(): sending response: VER: 5 REP: 6 FLAG: 0 ATYP: 1 address: 0.0.0.0.0, authmethod 0
Jul 17 19:13:16 (1689613996.358127) danted[828]: debug: io_delete(): command connect, bad-fd -1, controlfd -1, src-fd 12, dst-fd 13 dstc = 0
Jul 17 19:13:16 (1689613996.358152) danted[828]: debug: io_timeuntiltimeout(): timeouttype = 2, protocoltimeout = 30, tnow = 419990, lastio = 419958 (32s ago), timeout reached -2s ago
Jul 17 19:13:16 (1689613996.358156) danted[828]: info: pass(1): tcp/connect ]: 0 -> 172.18.0.1.50528 172.18.0.4.1080 -> 0, 0 -> 10.5.0.2.50528 172.64.163.15.443 -> 0: connect timeout.  Session duration: 32s
Jul 17 19:13:16 (1689613996.358167) danted[828]: debug: io_timeuntiltimeout(): timeouttype = 2, protocoltimeout = 30, tnow = 419990, lastio = 419958 (32s ago), timeout reached -2s ago
Jul 17 19:13:16 (1689613996.358170) danted[828]: info: pass(2): tcp/accept ]: 0 -> 172.18.0.1.50528 172.18.0.4.1080 -> 0: connect timeout.  Session duration: 32s
Jul 17 19:13:16 (1689613996.358173) danted[828]: debug: socks_freebuffer(): fd 12
Jul 17 19:13:16 (1689613996.358176) danted[828]: debug: socks_freebuffer(): fd 13
Jul 17 19:13:16 (1689613996.358323) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.358397) danted[792]: debug: handlechildcommand(): command 1 from io-child 828
Jul 17 19:13:16 (1689613996.358402) danted[792]: debug: handlechildcommand(): io-child 828 has freed a TCP slot, now has 31 slots free
Jul 17 19:13:16 (1689613996.358485) danted[792]: debug: calling select().  Free negc: 96, reqc: 16, ioc: 63
Jul 17 19:13:16 (1689613996.358552) danted[828]: debug: io_delete(): before SHMEM_UNUSE(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.358569) danted[828]: debug: io_delete(): before SHMEM_UNUSE(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.358887) danted[828]: debug: io_fillset_connectinprogress(): fd 11 marked as still connecting
Jul 17 19:13:16 (1689613996.358907) danted[828]: debug: run_io(): first select; readable/connected?
Jul 17 19:13:16 (1689613996.358912) danted[828]: debug: io_gettimeout(): last_time = 419989, tnow = 419990, last_timeout_isset = 1, last_timeout = 0.999999
Jul 17 19:13:16 (1689613996.358918) danted[828]: debug: io_gettimeout(): timeout for iov #0 is in 29s
Jul 17 19:13:16 (1689613996.396373) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.396373) danted[795]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.396439) danted[795]: debug: accepted tcp client 172.18.0.1.50736 on address 172.18.0.4.1080, fd 7
Jul 17 19:13:16 (1689613996.396446) danted[795]: debug: sending client 172.18.0.1.50736 to negotiate-child (pid 848 with 96 slots free)
Jul 17 19:13:16 (1689613996.396450) danted[795]: debug: send_client(): buflen = 0
Jul 17 19:13:16 (1689613996.396538) danted[792]: debug: calling select().  Free negc: 96, reqc: 16, ioc: 63
Jul 17 19:13:16 (1689613996.396582) danted[848]: debug: rulespermit(): 172.18.0.1.50736 -> 172.18.0.4.1080, clientauth N/A, srcauth notset, command accept, fd 8 from 172.18.0.1.50736, accepted on 172.18.0.4.1080
Jul 17 19:13:16 (1689613996.396592) danted[848]: debug: rulespermit(): trying to match against client-rule-rule #1, verdict = pass
Jul 17 19:13:16 (1689613996.396602) danted[848]: debug: addrmatch(): matching ruleaddress IPv4 address 10.0.0.0/8 against IPv4 address 172.18.0.1.50736 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.396607) danted[848]: debug: rulespermit(): trying to match against client-rule-rule #2, verdict = pass
Jul 17 19:13:16 (1689613996.396613) danted[848]: debug: addrmatch(): matching ruleaddress IPv4 address 172.16.0.0/12 against IPv4 address 172.18.0.1.50736 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.396618) danted[848]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 172.18.0.4.1080 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.396622) danted[848]: debug: methodisset(): checking if method notset is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.396626) danted[848]: debug: rulespermit(): changing authmethod from -1 to 0
Jul 17 19:13:16 (1689613996.396629) danted[848]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.396634) danted[848]: debug: accesscheck(): method: none, 172.18.0.1.50736 -> 172.18.0.4.1080 
Jul 17 19:13:16 (1689613996.396636) danted[848]: debug: methodisset(): checking if method none is set in the list (0) ""
Jul 17 19:13:16 (1689613996.396638) danted[848]: debug: methodisset(): checking if method none is set in the list (0) ""
Jul 17 19:13:16 (1689613996.396640) danted[848]: debug: accesscheck(): authentication matched
Jul 17 19:13:16 (1689613996.396649) danted[848]: debug: rulespermit(): rule matched: 2 (client-rule), verdict pass
Jul 17 19:13:16 (1689613996.396653) danted[848]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:16 (1689613996.396659) danted[848]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 6 (post-establishment or any time)
Jul 17 19:13:16 (1689613996.396661) danted[848]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:16 (1689613996.396667) danted[848]: debug: shmem_userule(): cinfo: 172.18.0.1.50736
Jul 17 19:13:16 (1689613996.396669) danted[848]: debug: shmem_userule(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.396684) danted[848]: info: pass(2): tcp/accept [: 172.18.0.1.50736 172.18.0.4.1080
Jul 17 19:13:16 (1689613996.396687) danted[848]: debug: socks_allocbuffer(): fd 8, stype = 1
Jul 17 19:13:16 (1689613996.396764) danted[848]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:16 (1689613996.396770) danted[848]: debug: recv_negotiate(): recvmsg() from mother returned -1 after having received 1 new clients (0 failed/blocked clients).  errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:16 (1689613996.396984) danted[795]: debug: calling select().  Free negc: 191, reqc: 16, ioc: 62
Jul 17 19:13:16 (1689613996.397363) danted[848]: debug: recv_clientrequest(): fd 8, client 172.18.0.1.50736, state->complete: 0, read so far: 0
Jul 17 19:13:16 (1689613996.397396) danted[848]: debug: recv_clientrequest(): initiating negotiation with client at 172.18.0.1.50736 which connected to us on 172.18.0.4.1080
Jul 17 19:13:16 (1689613996.397406) danted[848]: debug: recv_methods(): client 172.18.0.1.50736 offered 1 authentication method: 0x0 (none)
Jul 17 19:13:16 (1689613996.397451) danted[848]: debug: recv_methods(): socksmethod to use not set, selecting amongst the following 1 method: none
Jul 17 19:13:16 (1689613996.397454) danted[848]: debug: recv_methods(): sending authentication reply: VER: 5 METHOD: 0 (none)
Jul 17 19:13:16 (1689613996.397502) danted[848]: debug: run_negotiate(): recv_clientrequest() from client 172.18.0.1.50736 returned 2, errno is 0 (no error)
Jul 17 19:13:16 (1689613996.398192) danted[848]: debug: recv_clientrequest(): fd 8, client 172.18.0.1.50736, state->complete: 0, read so far: 3
Jul 17 19:13:16 (1689613996.398227) danted[848]: debug: run_negotiate(): recv_clientrequest() from client 172.18.0.1.50736 returned 3, errno is 0 (no error)
Jul 17 19:13:16 (1689613996.398235) danted[848]: debug: send_negotiate(): no shmem to unuse/clear
Jul 17 19:13:16 (1689613996.398253) danted[848]: debug: send_negotiate(): client 172.18.0.1.50736 finished negotiate phase for command connect using proxyprotocol socks_v5
Jul 17 19:13:16 (1689613996.398287) danted[848]: debug: delete_negotiate(): forwardedtomother: 1
Jul 17 19:13:16 (1689613996.398292) danted[848]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:16 (1689613996.398468) danted[795]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.398486) danted[795]: debug: trying to receive request from negotiate-child 848
Jul 17 19:13:16 (1689613996.398521) danted[795]: debug: sending client 172.18.0.1.50736 to request-child (pid 805 with 1 slots free)
Jul 17 19:13:16 (1689613996.398666) danted[805]: debug: dorequest(): command 1 request received from client 172.18.0.1.50736.  Accepted on 172.18.0.4.1080, matched by client-rule #2, auth: none.  Packet: VER: 5 CMD: 1 FLAG: 0 ATYP: 3 address: firefox.settings.services.mozilla.com.443 
Jul 17 19:13:16 (1689613996.398738) danted[805]: debug: socks_allocbuffer(): fd 8, stype = 1
Jul 17 19:13:16 (1689613996.398994) danted[805]: debug: reqhostisok(): host firefox.settings.services.mozilla.com.443, command connect
Jul 17 19:13:16 (1689613996.399018) danted[805]: debug: set_hints_ai_family: ai_family = 2
Jul 17 19:13:16 (1689613996.399029) danted[805]: debug: cgetaddrinfo(), hit: 0, miss: 0
Jul 17 19:13:16 (1689613996.399082) danted[805]: debug: reqhostisok(): hostname firefox.settings.services.mozilla.com.443 in connect-request resolved to address 34.149.100.209.443
Jul 17 19:13:16 (1689613996.399106) danted[805]: debug: rulespermit(): 172.18.0.1.50736 -> firefox.settings.services.mozilla.com.443, clientauth none, srcauth none, command connect, fd 8 from 172.18.0.1.50736, accepted on 172.18.0.4.1080
Jul 17 19:13:16 (1689613996.399133) danted[805]: debug: rulespermit(): trying to match against socks-rule-rule #1, verdict = pass
Jul 17 19:13:16 (1689613996.399150) danted[805]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 172.18.0.1.50736 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.399160) danted[805]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against host/domain-name firefox.settings.services.mozilla.com.443 for protocol tcp, without alias
Jul 17 19:13:16 (1689613996.399173) danted[805]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.399177) danted[805]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.399180) danted[805]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.399188) danted[805]: debug: accesscheck(): method: none, 172.18.0.1.50736 -> 172.18.0.4.1080 
Jul 17 19:13:16 (1689613996.399191) danted[805]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:16 (1689613996.399193) danted[805]: debug: accesscheck(): method none already checked, matches
Jul 17 19:13:16 (1689613996.399198) danted[805]: debug: rulespermit(): rule matched: 1 (socks-rule), verdict pass
Jul 17 19:13:16 (1689613996.399208) danted[805]: debug: dorequest(): client requested target firefox.settings.services.mozilla.com.443, we will use 34.149.100.209.443
Jul 17 19:13:16 (1689613996.399223) danted[805]: debug: rule_inheritoruse(): from-rule before (cinfo: 172.18.0.1.50736): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.399232) danted[805]: debug: rule_inheritoruse(): to-rule before (cinfo: 172.18.0.1.50736): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.399237) danted[805]: debug: rule_inheritoruse(): no session settings in client-rule #2 to consider for inheritance
Jul 17 19:13:16 (1689613996.399240) danted[805]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:16 (1689613996.399242) danted[805]: debug: rule_inheritoruse(): no bandwidth settings in client-rule #2 to consider for inheritance
Jul 17 19:13:16 (1689613996.399244) danted[805]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:16 (1689613996.399248) danted[805]: debug: alarm_inherit: sidesconnected: 1
Jul 17 19:13:16 (1689613996.399252) danted[805]: debug: alarm_inherit: from-rule: shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.399255) danted[805]: debug: alarm_inherit: to-rule: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.399258) danted[805]: debug: rule_inheritoruse(): no mstats settings in client-rule #2 to consider for inheritance
Jul 17 19:13:16 (1689613996.399261) danted[805]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:16 (1689613996.399264) danted[805]: debug: rule_inheritoruse(): from-rule after: shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.399267) danted[805]: debug: rule_inheritoruse(): to-rule after: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.399277) danted[805]: debug: bindexternaladdr(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.149.100.209.443, authmethod 0
Jul 17 19:13:16 (1689613996.399283) danted[805]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.149.100.209.443, authmethod 0
Jul 17 19:13:16 (1689613996.399285) danted[805]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:16 (1689613996.399292) danted[805]: debug: getoutaddr(): client 172.18.0.1.50736, cmd connect, reqhost 34.149.100.209.443, external.rotation = none
Jul 17 19:13:16 (1689613996.399296) danted[805]: debug: getdefaultexternal(): looking for an IPv4 address with scopeid 0/global, ifindex 0
Jul 17 19:13:16 (1689613996.399485) danted[805]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:16 (1689613996.399495) danted[805]: debug: getdefaultexternal(): matched IPv4 address 10.5.0.2.0
Jul 17 19:13:16 (1689613996.399502) danted[805]: debug: addrindex_on_externallist(): checking if address 10.5.0.2.0 is a configured external address
Jul 17 19:13:16 (1689613996.399509) danted[805]: debug: addrindex_on_externallist(): external address #0: interfacename nordlynx
Jul 17 19:13:16 (1689613996.399575) danted[805]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:16 (1689613996.399588) danted[805]: debug: getoutaddr(): local address 10.5.0.2 selected for forwarding from client 172.18.0.1.50736 to 34.149.100.209.443
Jul 17 19:13:16 (1689613996.399603) danted[805]: debug: socks_bind(): trying to bind address 10.5.0.2.50736 on fd 10.  Retries is 0
Jul 17 19:13:16 (1689613996.399616) danted[805]: debug: socks_bind(): bound address 10.5.0.2.50736 on fd 10
Jul 17 19:13:16 (1689613996.399620) danted[805]: debug: bindexternaladdr(): bound address on external side is 10.5.0.2.50736
Jul 17 19:13:16 (1689613996.399625) danted[805]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:16 (1689613996.399631) danted[805]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:16 (1689613996.399637) danted[805]: debug: setsockoptions(): fd 10, type = 1, isclientside = 0
Jul 17 19:13:16 (1689613996.399642) danted[805]: debug: setsockoptions(): 3 options to set
Jul 17 19:13:16 (1689613996.399651) danted[805]: debug: setnonblocking(): fd 10: setsockoptions()
Jul 17 19:13:16 (1689613996.399655) danted[805]: debug: setsockoptions(): buffer sizes for fd 10 are: SO_SNDBUF: 16384, SO_RCVBUF: 87380
Jul 17 19:13:16 (1689613996.399658) danted[805]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 10 (in: 8) on the external side
Jul 17 19:13:16 (1689613996.399661) danted[805]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 5 (pre-establishment or any time)
Jul 17 19:13:16 (1689613996.399664) danted[805]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 5
Jul 17 19:13:16 (1689613996.399671) danted[805]: debug: serverchain(): client 172.18.0.1.50736, auth none, request VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.149.100.209.443
Jul 17 19:13:16 (1689613996.399676) danted[805]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 34.149.100.209.443, authmethod 0
Jul 17 19:13:16 (1689613996.399678) danted[805]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:16 (1689613996.399681) danted[805]: debug: serverchain(): using direct system calls for fd 10
Jul 17 19:13:16 (1689613996.399709) danted[805]: debug: socks_connecthost(): connect to 34.149.100.209.443 on external/target side from 10.5.0.2.50736, fd 10.  Timeout is 0
Jul 17 19:13:16 (1689613996.399838) danted[805]: debug: socks_connecthost(): connect(2) to 34.149.100.209.443 from 10.5.0.2.50736 on fd 10 returned -1 (Operation now in progress)
Jul 17 19:13:16 (1689613996.399846) danted[805]: debug: socks_connecthost(): connect to 34.149.100.209.443 from 10.5.0.2.50736 on fd 10 in progress (Operation now in progress)
Jul 17 19:13:16 (1689613996.399849) danted[805]: debug: connect to host 34.149.100.209.443 is now in progress
Jul 17 19:13:16 (1689613996.399860) danted[805]: debug: flushio(): io->control.s = fd -1, io->src.s = fd 8, io->dst.s = fd 10
Jul 17 19:13:16 (1689613996.399866) danted[805]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.399871) danted[805]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.399924) danted[805]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:16 (1689613996.399991) danted[795]: debug: handlechildcommand(): command 1 from negotiate-child 848
Jul 17 19:13:16 (1689613996.399998) danted[795]: debug: handlechildcommand(): negotiate-child 848 has freed a TCP slot, now has 96 slots free
Jul 17 19:13:16 (1689613996.400028) danted[795]: debug: childcheck(): current # of free request-child slots is 15, configured minimum is 16: need to add more request-children
Jul 17 19:13:16 (1689613996.400032) danted[795]: debug: addchild(): type is request-child
Jul 17 19:13:16 (1689613996.400049) danted[795]: debug: setnonblocking(): fd 55: pipe between moter and child
Jul 17 19:13:16 (1689613996.400053) danted[795]: debug: setnonblocking(): fd 60: pipe between moter and child
Jul 17 19:13:16 (1689613996.400055) danted[795]: debug: setnonblocking(): fd 22: pipe between moter and child
Jul 17 19:13:16 (1689613996.400058) danted[795]: debug: setnonblocking(): fd 25: pipe between moter and child
Jul 17 19:13:16 (1689613996.400061) danted[795]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:16 (1689613996.400072) danted[795]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:16 (1689613996.400088) danted[795]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:16 (1689613996.400091) danted[795]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:16 (1689613996.400098) danted[795]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:16 (1689613996.400101) danted[795]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:16 (1689613996.400107) danted[795]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:16 (1689613996.400110) danted[795]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:16 (1689613996.400116) danted[795]: debug: addchild(): highest fd in use at the moment: 60
Jul 17 19:13:16 (1689613996.400708) danted[795]: debug: addchild(): created new request-child with pid 854, data-pipe 22 and ack-pipe 55.  Minimum rcvbuf: 39160, set: 78320 and 78320.  Minimum sndbuf: 39160, set: 78320 and 78320
Jul 17 19:13:16 (1689613996.400739) danted[795]: debug: childcheck(): added child, pid 854
Jul 17 19:13:16 (1689613996.400818) danted[854]: debug: postconfigloadinit(): I am a request-child
Jul 17 19:13:16 (1689613996.400867) danted[854]: debug: sockd_setcpusettings(): old cpu scheduling policy/priority: other/0, new: other/0
Jul 17 19:13:16 (1689613996.400885) danted[854]: debug: request_postconfigload()
Jul 17 19:13:16 (1689613996.400928) danted[795]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 62
Jul 17 19:13:16 (1689613996.400972) danted[795]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:16 (1689613996.400978) danted[795]: debug: trying to receive request from request-child 805
Jul 17 19:13:16 (1689613996.400993) danted[854]: debug: addchild(): I am a new request-child with data-pipe 0 and ack-pipe 7
Jul 17 19:13:16 (1689613996.400999) danted[795]: debug: recv_io(): we are mother
Jul 17 19:13:16 (1689613996.401128) danted[795]: debug: sending client 172.18.0.1.50736 to io-child (pid 831 with 30 slots free)
Jul 17 19:13:16 (1689613996.401128) danted[854]: debug: sockd_print_child_ready_message(): I'm request-child and ready to serve with 1048567 free fds and 1 free slot
Jul 17 19:13:16 (1689613996.401134) danted[795]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.401140) danted[795]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.401173) danted[795]: debug: handlechildcommand(): command 1 from request-child 805
Jul 17 19:13:16 (1689613996.401178) danted[795]: debug: handlechildcommand(): request-child 805 has freed a TCP slot, now has 1 slot free
Jul 17 19:13:16 (1689613996.401193) danted[795]: debug: childcheck(): counted 16 free request-child slots.  Removing pid 805 which has handled 1 client during 85s
Jul 17 19:13:16 (1689613996.401198) danted[795]: debug: closechild(): pid = 805, isnormalexit = 1
Jul 17 19:13:16 (1689613996.401240) danted[805]: debug: run_request(): mother telling us to exit normally when done
Jul 17 19:13:16 (1689613996.401256) danted[805]: debug: sockdexit(): insignal = 0
Jul 17 19:13:16 (1689613996.401262) danted[805]: debug: request-child: shutting down
Jul 17 19:13:16 (1689613996.401820) danted[795]: debug: sockd_pushsignal(): pushed signal 17 from pid 805.  Number of signals on the stack is now 1
Jul 17 19:13:16 (1689613996.401898) danted[795]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 61
Jul 17 19:13:16 (1689613996.401909) danted[795]: debug: sockd_handledsignals(): signals left on the stack after popping signal 17: 0
Jul 17 19:13:16 (1689613996.401914) danted[795]: debug: SIGCHLD [: processing signal 17
Jul 17 19:13:16 (1689613996.401950) danted[795]: debug: sigchld(): process 805 exited
Jul 17 19:13:16 (1689613996.401956) danted[795]: debug: sigchld(): request-child-child 805 exiting after 85s and 1 client
Jul 17 19:13:16 (1689613996.401961) danted[795]: debug: resource usage for request-child-child 805
Jul 17 19:13:16 (1689613996.401967) danted[795]: debug: removechild(): pid = 805
Jul 17 19:13:16 (1689613996.401976) danted[795]: debug: SIGCHLD ]: finished processing signal 17
Jul 17 19:13:16 (1689613996.401996) danted[795]: debug: main(): selectn() returned -1 (Interrupted system call)
Jul 17 19:13:16 (1689613996.402011) danted[795]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 61
Jul 17 19:13:16 (1689613996.402096) danted[831]: debug: recv_io(): we are child
Jul 17 19:13:16 (1689613996.402163) danted[831]: debug: socks_allocbuffer(): fd 14, stype = 1
Jul 17 19:13:16 (1689613996.402227) danted[831]: debug: socks_allocbuffer(): fd 15, stype = 1
Jul 17 19:13:16 (1689613996.402268) danted[831]: debug: recv_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.402273) danted[831]: debug: recv_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:16 (1689613996.402278) danted[831]: debug: io_updatemonitor(): control-fd -1, src-fd 14, dst-fd 15, protocol tcp, command connect, mstats_shmid 0, at address (nil)
Jul 17 19:13:16 (1689613996.402292) danted[831]: debug: monitormatch(): 172.18.0.1.50736 -> 34.149.100.209.443
Jul 17 19:13:16 (1689613996.402295) danted[831]: debug: io_updatemonitor(): previously matched mstats_shmid 0, now matching monitor #0 with mstats_shmid 0 (same as now) and alarmsconfigured = 0
Jul 17 19:13:16 (1689613996.402299) danted[831]: debug: recv_io(): we are child
Jul 17 19:13:16 (1689613996.402309) danted[831]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:16 (1689613996.402314) danted[831]: debug: getnewios(): received 1 new io, errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:16 (1689613996.402564) danted[831]: debug: io_fillset_connectinprogress(): fd 11 marked as still connecting
Jul 17 19:13:16 (1689613996.402582) danted[831]: debug: io_fillset_connectinprogress(): fd 13 marked as still connecting
Jul 17 19:13:16 (1689613996.402585) danted[831]: debug: io_fillset_connectinprogress(): fd 15 marked as still connecting
Jul 17 19:13:16 (1689613996.402587) danted[831]: debug: run_io(): first select; readable/connected?
Jul 17 19:13:16 (1689613996.402591) danted[831]: debug: io_gettimeout(): last_time = 419990, tnow = 419990, last_timeout_isset = 1, last_timeout = 1.000000
Jul 17 19:13:17 (1689613997.403740) danted[831]: debug: io_fillset_connectinprogress(): fd 11 marked as still connecting
Jul 17 19:13:17 (1689613997.403787) danted[831]: debug: io_fillset_connectinprogress(): fd 13 marked as still connecting
Jul 17 19:13:17 (1689613997.403792) danted[831]: debug: io_fillset_connectinprogress(): fd 15 marked as still connecting
Jul 17 19:13:17 (1689613997.403795) danted[831]: debug: run_io(): first select; readable/connected?
Jul 17 19:13:17 (1689613997.403799) danted[831]: debug: io_gettimeout(): last_time = 419990, tnow = 419991, last_timeout_isset = 1, last_timeout = 1.000000
Jul 17 19:13:17 (1689613997.403806) danted[831]: debug: io_gettimeout(): timeout for iov #0 is in 29s
Jul 17 19:13:17 (1689613997.403809) danted[831]: debug: io_gettimeout(): timeout for iov #1 is in 28s
Jul 17 19:13:17 (1689613997.403811) danted[831]: debug: io_gettimeout(): timeout for iov #2 is in 29s
Jul 17 19:13:35 (1689614015.720770) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:35 (1689614015.720841) danted[792]: debug: accepted tcp client 172.18.0.1.50880 on address 172.18.0.4.1080, fd 7
Jul 17 19:13:35 (1689614015.720849) danted[792]: debug: sending client 172.18.0.1.50880 to negotiate-child (pid 850 with 96 slots free)
Jul 17 19:13:35 (1689614015.720853) danted[792]: debug: send_client(): buflen = 0
Jul 17 19:13:35 (1689614015.720910) danted[792]: debug: childcheck(): current # of free negotiate-child slots is 95, configured minimum is 96: need to add more negotiate-children
Jul 17 19:13:35 (1689614015.720916) danted[792]: debug: addchild(): type is negotiate-child
Jul 17 19:13:35 (1689614015.720933) danted[792]: debug: setnonblocking(): fd 23: pipe between moter and child
Jul 17 19:13:35 (1689614015.720938) danted[792]: debug: setnonblocking(): fd 55: pipe between moter and child
Jul 17 19:13:35 (1689614015.720940) danted[792]: debug: setnonblocking(): fd 20: pipe between moter and child
Jul 17 19:13:35 (1689614015.720943) danted[792]: debug: setnonblocking(): fd 21: pipe between moter and child
Jul 17 19:13:35 (1689614015.720946) danted[792]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:35 (1689614015.720962) danted[792]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:35 (1689614015.720978) danted[792]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:35 (1689614015.720981) danted[792]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:35 (1689614015.720988) danted[792]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:35 (1689614015.720991) danted[792]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:35 (1689614015.720998) danted[792]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:35 (1689614015.721001) danted[792]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:35 (1689614015.721006) danted[792]: debug: addchild(): highest fd in use at the moment: 60
Jul 17 19:13:35 (1689614015.721164) danted[850]: debug: rulespermit(): 172.18.0.1.50880 -> 172.18.0.4.1080, clientauth N/A, srcauth notset, command accept, fd 8 from 172.18.0.1.50880, accepted on 172.18.0.4.1080
Jul 17 19:13:35 (1689614015.721252) danted[850]: debug: rulespermit(): trying to match against client-rule-rule #1, verdict = pass
Jul 17 19:13:35 (1689614015.721280) danted[850]: debug: addrmatch(): matching ruleaddress IPv4 address 10.0.0.0/8 against IPv4 address 172.18.0.1.50880 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.721286) danted[850]: debug: rulespermit(): trying to match against client-rule-rule #2, verdict = pass
Jul 17 19:13:35 (1689614015.721292) danted[850]: debug: addrmatch(): matching ruleaddress IPv4 address 172.16.0.0/12 against IPv4 address 172.18.0.1.50880 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.721298) danted[850]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 172.18.0.4.1080 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.721310) danted[850]: debug: methodisset(): checking if method notset is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.721317) danted[850]: debug: rulespermit(): changing authmethod from -1 to 0
Jul 17 19:13:35 (1689614015.721321) danted[850]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.721328) danted[850]: debug: accesscheck(): method: none, 172.18.0.1.50880 -> 172.18.0.4.1080 
Jul 17 19:13:35 (1689614015.721331) danted[850]: debug: methodisset(): checking if method none is set in the list (0) ""
Jul 17 19:13:35 (1689614015.721334) danted[850]: debug: methodisset(): checking if method none is set in the list (0) ""
Jul 17 19:13:35 (1689614015.721336) danted[850]: debug: accesscheck(): authentication matched
Jul 17 19:13:35 (1689614015.721345) danted[850]: debug: rulespermit(): rule matched: 2 (client-rule), verdict pass
Jul 17 19:13:35 (1689614015.721353) danted[850]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:35 (1689614015.721362) danted[850]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 6 (post-establishment or any time)
Jul 17 19:13:35 (1689614015.721365) danted[850]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:35 (1689614015.721379) danted[850]: debug: shmem_userule(): cinfo: 172.18.0.1.50880
Jul 17 19:13:35 (1689614015.721384) danted[850]: debug: shmem_userule(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.721441) danted[850]: info: pass(2): tcp/accept [: 172.18.0.1.50880 172.18.0.4.1080
Jul 17 19:13:35 (1689614015.721450) danted[850]: debug: socks_allocbuffer(): fd 8, stype = 1
Jul 17 19:13:35 (1689614015.721483) danted[792]: debug: addchild(): created new negotiate-child with pid 855, data-pipe 20 and ack-pipe 23.  Minimum rcvbuf: 24536, set: 49072 and 49072.  Minimum sndbuf: 2355456, set: 4710912 and 4710912
Jul 17 19:13:35 (1689614015.721499) danted[792]: debug: childcheck(): added child, pid 855
Jul 17 19:13:35 (1689614015.721645) danted[855]: debug: postconfigloadinit(): I am a negotiate-child
Jul 17 19:13:35 (1689614015.721706) danted[792]: debug: calling select().  Free negc: 191, reqc: 16, ioc: 63
Jul 17 19:13:35 (1689614015.721707) danted[850]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:35 (1689614015.721718) danted[850]: debug: recv_negotiate(): recvmsg() from mother returned -1 after having received 1 new clients (0 failed/blocked clients).  errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:35 (1689614015.721726) danted[855]: debug: sockd_setcpusettings(): old cpu scheduling policy/priority: other/0, new: other/0
Jul 17 19:13:35 (1689614015.721755) danted[855]: debug: negotiate_postconfigload()
Jul 17 19:13:35 (1689614015.721893) danted[850]: debug: recv_clientrequest(): fd 8, client 172.18.0.1.50880, state->complete: 0, read so far: 0
Jul 17 19:13:35 (1689614015.721953) danted[850]: debug: recv_clientrequest(): initiating negotiation with client at 172.18.0.1.50880 which connected to us on 172.18.0.4.1080
Jul 17 19:13:35 (1689614015.721961) danted[855]: debug: addchild(): I am a new negotiate-child with data-pipe 0 and ack-pipe 7
Jul 17 19:13:35 (1689614015.721977) danted[850]: debug: recv_methods(): client 172.18.0.1.50880 offered 1 authentication method: 0x0 (none)
Jul 17 19:13:35 (1689614015.721984) danted[850]: debug: recv_methods(): socksmethod to use not set, selecting amongst the following 1 method: none
Jul 17 19:13:35 (1689614015.721988) danted[850]: debug: recv_methods(): sending authentication reply: VER: 5 METHOD: 0 (none)
Jul 17 19:13:35 (1689614015.722075) danted[855]: debug: sockd_print_child_ready_message(): I'm negotiate-child and ready to serve with 1048567 free fds and 96 free slots
Jul 17 19:13:35 (1689614015.722124) danted[850]: debug: run_negotiate(): recv_clientrequest() from client 172.18.0.1.50880 returned 2, errno is 0 (no error)
Jul 17 19:13:35 (1689614015.722659) danted[850]: debug: recv_clientrequest(): fd 8, client 172.18.0.1.50880, state->complete: 0, read so far: 3
Jul 17 19:13:35 (1689614015.722705) danted[850]: debug: run_negotiate(): recv_clientrequest() from client 172.18.0.1.50880 returned 3, errno is 0 (no error)
Jul 17 19:13:35 (1689614015.722714) danted[850]: debug: send_negotiate(): no shmem to unuse/clear
Jul 17 19:13:35 (1689614015.722729) danted[850]: debug: send_negotiate(): client 172.18.0.1.50880 finished negotiate phase for command connect using proxyprotocol socks_v5
Jul 17 19:13:35 (1689614015.722766) danted[850]: debug: delete_negotiate(): forwardedtomother: 1
Jul 17 19:13:35 (1689614015.722770) danted[850]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:35 (1689614015.722838) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:35 (1689614015.722853) danted[792]: debug: trying to receive request from negotiate-child 850
Jul 17 19:13:35 (1689614015.722936) danted[792]: debug: sending client 172.18.0.1.50880 to request-child (pid 802 with 1 slots free)
Jul 17 19:13:35 (1689614015.722968) danted[792]: debug: handlechildcommand(): command 1 from negotiate-child 850
Jul 17 19:13:35 (1689614015.722972) danted[792]: debug: handlechildcommand(): negotiate-child 850 has freed a TCP slot, now has 96 slots free
Jul 17 19:13:35 (1689614015.723019) danted[792]: debug: childcheck(): current # of free request-child slots is 15, configured minimum is 16: need to add more request-children
Jul 17 19:13:35 (1689614015.723024) danted[792]: debug: addchild(): type is request-child
Jul 17 19:13:35 (1689614015.723044) danted[792]: debug: setnonblocking(): fd 58: pipe between moter and child
Jul 17 19:13:35 (1689614015.723049) danted[792]: debug: setnonblocking(): fd 60: pipe between moter and child
Jul 17 19:13:35 (1689614015.723051) danted[792]: debug: setnonblocking(): fd 21: pipe between moter and child
Jul 17 19:13:35 (1689614015.723053) danted[792]: debug: setnonblocking(): fd 55: pipe between moter and child
Jul 17 19:13:35 (1689614015.723056) danted[792]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:35 (1689614015.723078) danted[792]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:35 (1689614015.723099) danted[792]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:35 (1689614015.723103) danted[792]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:35 (1689614015.723109) danted[792]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:35 (1689614015.723112) danted[792]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:35 (1689614015.723118) danted[792]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:35 (1689614015.723121) danted[792]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:35 (1689614015.723127) danted[792]: debug: addchild(): highest fd in use at the moment: 60
Jul 17 19:13:35 (1689614015.723581) danted[802]: debug: dorequest(): command 1 request received from client 172.18.0.1.50880.  Accepted on 172.18.0.4.1080, matched by client-rule #2, auth: none.  Packet: VER: 5 CMD: 1 FLAG: 0 ATYP: 3 address: mozilla.cloudflare-dns.com.443 
Jul 17 19:13:35 (1689614015.723660) danted[792]: debug: addchild(): created new request-child with pid 856, data-pipe 21 and ack-pipe 58.  Minimum rcvbuf: 39160, set: 78320 and 78320.  Minimum sndbuf: 39160, set: 78320 and 78320
Jul 17 19:13:35 (1689614015.723671) danted[802]: debug: socks_allocbuffer(): fd 8, stype = 1
Jul 17 19:13:35 (1689614015.723682) danted[792]: debug: childcheck(): added child, pid 856
Jul 17 19:13:35 (1689614015.723867) danted[792]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 63
Jul 17 19:13:35 (1689614015.723943) danted[802]: debug: reqhostisok(): host mozilla.cloudflare-dns.com.443, command connect
Jul 17 19:13:35 (1689614015.723971) danted[802]: debug: set_hints_ai_family: ai_family = 2
Jul 17 19:13:35 (1689614015.723984) danted[802]: debug: cgetaddrinfo(), hit: 0, miss: 0
Jul 17 19:13:35 (1689614015.724043) danted[802]: debug: reqhostisok(): hostname mozilla.cloudflare-dns.com.443 in connect-request resolved to address 162.159.61.4.443
Jul 17 19:13:35 (1689614015.724068) danted[802]: debug: rulespermit(): 172.18.0.1.50880 -> mozilla.cloudflare-dns.com.443, clientauth none, srcauth none, command connect, fd 8 from 172.18.0.1.50880, accepted on 172.18.0.4.1080
Jul 17 19:13:35 (1689614015.724102) danted[802]: debug: rulespermit(): trying to match against socks-rule-rule #1, verdict = pass
Jul 17 19:13:35 (1689614015.724118) danted[802]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 172.18.0.1.50880 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.724128) danted[802]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against host/domain-name mozilla.cloudflare-dns.com.443 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.724114) danted[856]: debug: postconfigloadinit(): I am a request-child
Jul 17 19:13:35 (1689614015.724147) danted[802]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.724153) danted[802]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.724156) danted[802]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.724164) danted[802]: debug: accesscheck(): method: none, 172.18.0.1.50880 -> 172.18.0.4.1080 
Jul 17 19:13:35 (1689614015.724167) danted[802]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.724169) danted[802]: debug: accesscheck(): method none already checked, matches
Jul 17 19:13:35 (1689614015.724162) danted[856]: debug: sockd_setcpusettings(): old cpu scheduling policy/priority: other/0, new: other/0
Jul 17 19:13:35 (1689614015.724175) danted[802]: debug: rulespermit(): rule matched: 1 (socks-rule), verdict pass
Jul 17 19:13:35 (1689614015.724180) danted[856]: debug: request_postconfigload()
Jul 17 19:13:35 (1689614015.724186) danted[802]: debug: dorequest(): client requested target mozilla.cloudflare-dns.com.443, we will use 172.64.41.4.443
Jul 17 19:13:35 (1689614015.724201) danted[802]: debug: rule_inheritoruse(): from-rule before (cinfo: 172.18.0.1.50880): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.724211) danted[802]: debug: rule_inheritoruse(): to-rule before (cinfo: 172.18.0.1.50880): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.724216) danted[802]: debug: rule_inheritoruse(): no session settings in client-rule #2 to consider for inheritance
Jul 17 19:13:35 (1689614015.724219) danted[802]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:35 (1689614015.724222) danted[802]: debug: rule_inheritoruse(): no bandwidth settings in client-rule #2 to consider for inheritance
Jul 17 19:13:35 (1689614015.724225) danted[802]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:35 (1689614015.724229) danted[802]: debug: alarm_inherit: sidesconnected: 1
Jul 17 19:13:35 (1689614015.724233) danted[802]: debug: alarm_inherit: from-rule: shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.724236) danted[802]: debug: alarm_inherit: to-rule: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.724239) danted[802]: debug: rule_inheritoruse(): no mstats settings in client-rule #2 to consider for inheritance
Jul 17 19:13:35 (1689614015.724241) danted[802]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:35 (1689614015.724243) danted[802]: debug: rule_inheritoruse(): from-rule after: shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.724246) danted[802]: debug: rule_inheritoruse(): to-rule after: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.724258) danted[802]: debug: bindexternaladdr(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 172.64.41.4.443, authmethod 0
Jul 17 19:13:35 (1689614015.724264) danted[802]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 172.64.41.4.443, authmethod 0
Jul 17 19:13:35 (1689614015.724267) danted[802]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:35 (1689614015.724274) danted[802]: debug: getoutaddr(): client 172.18.0.1.50880, cmd connect, reqhost 172.64.41.4.443, external.rotation = none
Jul 17 19:13:35 (1689614015.724273) danted[856]: debug: addchild(): I am a new request-child with data-pipe 0 and ack-pipe 7
Jul 17 19:13:35 (1689614015.724279) danted[802]: debug: getdefaultexternal(): looking for an IPv4 address with scopeid 0/global, ifindex 0
Jul 17 19:13:35 (1689614015.724342) danted[856]: debug: sockd_print_child_ready_message(): I'm request-child and ready to serve with 1048567 free fds and 1 free slot
Jul 17 19:13:35 (1689614015.724464) danted[802]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:35 (1689614015.724477) danted[802]: debug: getdefaultexternal(): matched IPv4 address 10.5.0.2.0
Jul 17 19:13:35 (1689614015.724484) danted[802]: debug: addrindex_on_externallist(): checking if address 10.5.0.2.0 is a configured external address
Jul 17 19:13:35 (1689614015.724492) danted[802]: debug: addrindex_on_externallist(): external address #0: interfacename nordlynx
Jul 17 19:13:35 (1689614015.724562) danted[802]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:35 (1689614015.724575) danted[802]: debug: getoutaddr(): local address 10.5.0.2 selected for forwarding from client 172.18.0.1.50880 to 172.64.41.4.443
Jul 17 19:13:35 (1689614015.724591) danted[802]: debug: socks_bind(): trying to bind address 10.5.0.2.50880 on fd 10.  Retries is 0
Jul 17 19:13:35 (1689614015.724604) danted[802]: debug: socks_bind(): bound address 10.5.0.2.50880 on fd 10
Jul 17 19:13:35 (1689614015.724609) danted[802]: debug: bindexternaladdr(): bound address on external side is 10.5.0.2.50880
Jul 17 19:13:35 (1689614015.724614) danted[802]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:35 (1689614015.724620) danted[802]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:35 (1689614015.724626) danted[802]: debug: setsockoptions(): fd 10, type = 1, isclientside = 0
Jul 17 19:13:35 (1689614015.724631) danted[802]: debug: setsockoptions(): 3 options to set
Jul 17 19:13:35 (1689614015.724638) danted[802]: debug: setnonblocking(): fd 10: setsockoptions()
Jul 17 19:13:35 (1689614015.724642) danted[802]: debug: setsockoptions(): buffer sizes for fd 10 are: SO_SNDBUF: 16384, SO_RCVBUF: 87380
Jul 17 19:13:35 (1689614015.724647) danted[802]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 10 (in: 8) on the external side
Jul 17 19:13:35 (1689614015.724650) danted[802]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 5 (pre-establishment or any time)
Jul 17 19:13:35 (1689614015.724653) danted[802]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 5
Jul 17 19:13:35 (1689614015.724660) danted[802]: debug: serverchain(): client 172.18.0.1.50880, auth none, request VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 172.64.41.4.443
Jul 17 19:13:35 (1689614015.724666) danted[802]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 172.64.41.4.443, authmethod 0
Jul 17 19:13:35 (1689614015.724668) danted[802]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:35 (1689614015.724670) danted[802]: debug: serverchain(): using direct system calls for fd 10
Jul 17 19:13:35 (1689614015.724692) danted[802]: debug: socks_connecthost(): connect to 172.64.41.4.443 on external/target side from 10.5.0.2.50880, fd 10.  Timeout is 0
Jul 17 19:13:35 (1689614015.724834) danted[802]: debug: socks_connecthost(): connect(2) to 172.64.41.4.443 from 10.5.0.2.50880 on fd 10 returned -1 (Operation now in progress)
Jul 17 19:13:35 (1689614015.724841) danted[802]: debug: socks_connecthost(): connect to 172.64.41.4.443 from 10.5.0.2.50880 on fd 10 in progress (Operation now in progress)
Jul 17 19:13:35 (1689614015.724845) danted[802]: debug: connect to host 172.64.41.4.443 is now in progress
Jul 17 19:13:35 (1689614015.724855) danted[802]: debug: flushio(): io->control.s = fd -1, io->src.s = fd 8, io->dst.s = fd 10
Jul 17 19:13:35 (1689614015.724862) danted[802]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.724866) danted[802]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.724941) danted[802]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:35 (1689614015.725056) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:35 (1689614015.725066) danted[792]: debug: trying to receive request from request-child 802
Jul 17 19:13:35 (1689614015.725086) danted[792]: debug: recv_io(): we are mother
Jul 17 19:13:35 (1689614015.725195) danted[792]: debug: sending client 172.18.0.1.50880 to io-child (pid 828 with 31 slots free)
Jul 17 19:13:35 (1689614015.725201) danted[792]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.725205) danted[792]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.725231) danted[792]: debug: handlechildcommand(): command 1 from request-child 802
Jul 17 19:13:35 (1689614015.725236) danted[792]: debug: handlechildcommand(): request-child 802 has freed a TCP slot, now has 1 slot free
Jul 17 19:13:35 (1689614015.725251) danted[792]: debug: childcheck(): counted 16 free request-child slots.  Removing pid 802 which has handled 1 client during 104s
Jul 17 19:13:35 (1689614015.725256) danted[792]: debug: closechild(): pid = 802, isnormalexit = 1
Jul 17 19:13:35 (1689614015.725249) danted[828]: debug: recv_io(): we are child
Jul 17 19:13:35 (1689614015.725306) danted[828]: debug: socks_allocbuffer(): fd 12, stype = 1
Jul 17 19:13:35 (1689614015.725332) danted[792]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 62
Jul 17 19:13:35 (1689614015.725371) danted[828]: debug: socks_allocbuffer(): fd 13, stype = 1
Jul 17 19:13:35 (1689614015.725437) danted[828]: debug: recv_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.725444) danted[802]: debug: run_request(): mother telling us to exit normally when done
Jul 17 19:13:35 (1689614015.725447) danted[828]: debug: recv_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.725455) danted[828]: debug: io_updatemonitor(): control-fd -1, src-fd 12, dst-fd 13, protocol tcp, command connect, mstats_shmid 0, at address (nil)
Jul 17 19:13:35 (1689614015.725467) danted[828]: debug: monitormatch(): 172.18.0.1.50880 -> 172.64.41.4.443
Jul 17 19:13:35 (1689614015.725466) danted[802]: debug: sockdexit(): insignal = 0
Jul 17 19:13:35 (1689614015.725471) danted[828]: debug: io_updatemonitor(): previously matched mstats_shmid 0, now matching monitor #0 with mstats_shmid 0 (same as now) and alarmsconfigured = 0
Jul 17 19:13:35 (1689614015.725473) danted[802]: debug: request-child: shutting down
Jul 17 19:13:35 (1689614015.725475) danted[828]: debug: recv_io(): we are child
Jul 17 19:13:35 (1689614015.725488) danted[828]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:35 (1689614015.725492) danted[828]: debug: getnewios(): received 1 new io, errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:35 (1689614015.725750) danted[828]: debug: io_fillset_connectinprogress(): fd 11 marked as still connecting
Jul 17 19:13:35 (1689614015.725763) danted[828]: debug: io_fillset_connectinprogress(): fd 13 marked as still connecting
Jul 17 19:13:35 (1689614015.725768) danted[828]: debug: run_io(): first select; readable/connected?
Jul 17 19:13:35 (1689614015.725772) danted[828]: debug: io_gettimeout(): last_time = 419990, tnow = 420009, last_timeout_isset = 1, last_timeout = 29.999999
Jul 17 19:13:35 (1689614015.725778) danted[828]: debug: io_gettimeout(): timeout for iov #0 is in 10s
Jul 17 19:13:35 (1689614015.725781) danted[828]: debug: io_gettimeout(): timeout for iov #1 is in 30s
Jul 17 19:13:35 (1689614015.726174) danted[792]: debug: sockd_pushsignal(): pushed signal 17 from pid 802.  Number of signals on the stack is now 1
Jul 17 19:13:35 (1689614015.726202) danted[792]: debug: sockd_handledsignals(): signals left on the stack after popping signal 17: 0
Jul 17 19:13:35 (1689614015.726214) danted[792]: debug: SIGCHLD [: processing signal 17
Jul 17 19:13:35 (1689614015.726259) danted[792]: debug: sigchld(): process 802 exited
Jul 17 19:13:35 (1689614015.726267) danted[792]: debug: sigchld(): request-child-child 802 exiting after 104s and 1 client
Jul 17 19:13:35 (1689614015.726274) danted[792]: debug: resource usage for request-child-child 802
Jul 17 19:13:35 (1689614015.726280) danted[792]: debug: removechild(): pid = 802
Jul 17 19:13:35 (1689614015.726290) danted[792]: debug: SIGCHLD ]: finished processing signal 17
Jul 17 19:13:35 (1689614015.726313) danted[792]: debug: main(): selectn() returned -1 (Interrupted system call)
Jul 17 19:13:35 (1689614015.726364) danted[792]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 62
Jul 17 19:13:35 (1689614015.980856) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:35 (1689614015.980868) danted[795]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:35 (1689614015.980916) danted[792]: debug: accepted tcp client 172.18.0.1.50883 on address 172.18.0.4.1080, fd 7
Jul 17 19:13:35 (1689614015.980923) danted[792]: debug: sending client 172.18.0.1.50883 to negotiate-child (pid 850 with 96 slots free)
Jul 17 19:13:35 (1689614015.980928) danted[792]: debug: send_client(): buflen = 0
Jul 17 19:13:35 (1689614015.980984) danted[795]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 61
Jul 17 19:13:35 (1689614015.981008) danted[792]: debug: calling select().  Free negc: 191, reqc: 16, ioc: 62
Jul 17 19:13:35 (1689614015.981112) danted[850]: debug: rulespermit(): 172.18.0.1.50883 -> 172.18.0.4.1080, clientauth N/A, srcauth notset, command accept, fd 8 from 172.18.0.1.50883, accepted on 172.18.0.4.1080
Jul 17 19:13:35 (1689614015.981122) danted[850]: debug: rulespermit(): trying to match against client-rule-rule #1, verdict = pass
Jul 17 19:13:35 (1689614015.981131) danted[850]: debug: addrmatch(): matching ruleaddress IPv4 address 10.0.0.0/8 against IPv4 address 172.18.0.1.50883 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.981137) danted[850]: debug: rulespermit(): trying to match against client-rule-rule #2, verdict = pass
Jul 17 19:13:35 (1689614015.981142) danted[850]: debug: addrmatch(): matching ruleaddress IPv4 address 172.16.0.0/12 against IPv4 address 172.18.0.1.50883 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.981147) danted[850]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 172.18.0.4.1080 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.981151) danted[850]: debug: methodisset(): checking if method notset is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.981154) danted[850]: debug: rulespermit(): changing authmethod from -1 to 0
Jul 17 19:13:35 (1689614015.981157) danted[850]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.981162) danted[850]: debug: accesscheck(): method: none, 172.18.0.1.50883 -> 172.18.0.4.1080 
Jul 17 19:13:35 (1689614015.981164) danted[850]: debug: methodisset(): checking if method none is set in the list (0) ""
Jul 17 19:13:35 (1689614015.981166) danted[850]: debug: methodisset(): checking if method none is set in the list (0) ""
Jul 17 19:13:35 (1689614015.981168) danted[850]: debug: accesscheck(): authentication matched
Jul 17 19:13:35 (1689614015.981175) danted[850]: debug: rulespermit(): rule matched: 2 (client-rule), verdict pass
Jul 17 19:13:35 (1689614015.981178) danted[850]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:35 (1689614015.981184) danted[850]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 6 (post-establishment or any time)
Jul 17 19:13:35 (1689614015.981186) danted[850]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:35 (1689614015.981191) danted[850]: debug: shmem_userule(): cinfo: 172.18.0.1.50883
Jul 17 19:13:35 (1689614015.981194) danted[850]: debug: shmem_userule(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.981207) danted[850]: info: pass(2): tcp/accept [: 172.18.0.1.50883 172.18.0.4.1080
Jul 17 19:13:35 (1689614015.981210) danted[850]: debug: socks_allocbuffer(): fd 8, stype = 1
Jul 17 19:13:35 (1689614015.981279) danted[850]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:35 (1689614015.981284) danted[850]: debug: recv_negotiate(): recvmsg() from mother returned -1 after having received 1 new clients (0 failed/blocked clients).  errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:35 (1689614015.981404) danted[850]: debug: recv_clientrequest(): fd 8, client 172.18.0.1.50883, state->complete: 0, read so far: 0
Jul 17 19:13:35 (1689614015.981472) danted[850]: debug: recv_clientrequest(): initiating negotiation with client at 172.18.0.1.50883 which connected to us on 172.18.0.4.1080
Jul 17 19:13:35 (1689614015.981481) danted[850]: debug: recv_methods(): client 172.18.0.1.50883 offered 1 authentication method: 0x0 (none)
Jul 17 19:13:35 (1689614015.981485) danted[850]: debug: recv_methods(): socksmethod to use not set, selecting amongst the following 1 method: none
Jul 17 19:13:35 (1689614015.981488) danted[850]: debug: recv_methods(): sending authentication reply: VER: 5 METHOD: 0 (none)
Jul 17 19:13:35 (1689614015.981597) danted[850]: debug: run_negotiate(): recv_clientrequest() from client 172.18.0.1.50883 returned 2, errno is 0 (no error)
Jul 17 19:13:35 (1689614015.982058) danted[850]: debug: recv_clientrequest(): fd 8, client 172.18.0.1.50883, state->complete: 0, read so far: 3
Jul 17 19:13:35 (1689614015.982097) danted[850]: debug: run_negotiate(): recv_clientrequest() from client 172.18.0.1.50883 returned 3, errno is 0 (no error)
Jul 17 19:13:35 (1689614015.982105) danted[850]: debug: send_negotiate(): no shmem to unuse/clear
Jul 17 19:13:35 (1689614015.982123) danted[850]: debug: send_negotiate(): client 172.18.0.1.50883 finished negotiate phase for command connect using proxyprotocol socks_v5
Jul 17 19:13:35 (1689614015.982158) danted[850]: debug: delete_negotiate(): forwardedtomother: 1
Jul 17 19:13:35 (1689614015.982163) danted[850]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:35 (1689614015.982320) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:35 (1689614015.982335) danted[792]: debug: trying to receive request from negotiate-child 850
Jul 17 19:13:35 (1689614015.982371) danted[792]: debug: sending client 172.18.0.1.50883 to request-child (pid 804 with 1 slots free)
Jul 17 19:13:35 (1689614015.982402) danted[792]: debug: handlechildcommand(): command 1 from negotiate-child 850
Jul 17 19:13:35 (1689614015.982433) danted[792]: debug: handlechildcommand(): negotiate-child 850 has freed a TCP slot, now has 96 slots free
Jul 17 19:13:35 (1689614015.982472) danted[792]: debug: childcheck(): current # of free request-child slots is 15, configured minimum is 16: need to add more request-children
Jul 17 19:13:35 (1689614015.982477) danted[792]: debug: addchild(): type is request-child
Jul 17 19:13:35 (1689614015.982497) danted[792]: debug: setnonblocking(): fd 55: pipe between moter and child
Jul 17 19:13:35 (1689614015.982501) danted[792]: debug: setnonblocking(): fd 60: pipe between moter and child
Jul 17 19:13:35 (1689614015.982504) danted[792]: debug: setnonblocking(): fd 22: pipe between moter and child
Jul 17 19:13:35 (1689614015.982506) danted[792]: debug: setnonblocking(): fd 25: pipe between moter and child
Jul 17 19:13:35 (1689614015.982509) danted[792]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:35 (1689614015.982532) danted[792]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:35 (1689614015.982550) danted[792]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:35 (1689614015.982553) danted[792]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:35 (1689614015.982560) danted[792]: debug: sockd_priv(): switching privilege 6 on
Jul 17 19:13:35 (1689614015.982563) danted[792]: debug: sockd_setugid(): old uid/gid: 65534/65534, new: 0/0
Jul 17 19:13:35 (1689614015.982569) danted[792]: debug: sockd_priv(): switching privilege 6 off
Jul 17 19:13:35 (1689614015.982572) danted[792]: debug: sockd_setugid(): old uid/gid: 0/0, new: 65534/65534
Jul 17 19:13:35 (1689614015.982577) danted[792]: debug: addchild(): highest fd in use at the moment: 60
Jul 17 19:13:35 (1689614015.982627) danted[804]: debug: dorequest(): command 1 request received from client 172.18.0.1.50883.  Accepted on 172.18.0.4.1080, matched by client-rule #2, auth: none.  Packet: VER: 5 CMD: 1 FLAG: 0 ATYP: 3 address: mozilla.cloudflare-dns.com.443 
Jul 17 19:13:35 (1689614015.982703) danted[804]: debug: socks_allocbuffer(): fd 8, stype = 1
Jul 17 19:13:35 (1689614015.982958) danted[804]: debug: reqhostisok(): host mozilla.cloudflare-dns.com.443, command connect
Jul 17 19:13:35 (1689614015.982994) danted[804]: debug: set_hints_ai_family: ai_family = 2
Jul 17 19:13:35 (1689614015.983005) danted[804]: debug: cgetaddrinfo(), hit: 0, miss: 0
Jul 17 19:13:35 (1689614015.983065) danted[804]: debug: reqhostisok(): hostname mozilla.cloudflare-dns.com.443 in connect-request resolved to address 162.159.61.4.443
Jul 17 19:13:35 (1689614015.983092) danted[804]: debug: rulespermit(): 172.18.0.1.50883 -> mozilla.cloudflare-dns.com.443, clientauth none, srcauth none, command connect, fd 8 from 172.18.0.1.50883, accepted on 172.18.0.4.1080
Jul 17 19:13:35 (1689614015.983130) danted[804]: debug: rulespermit(): trying to match against socks-rule-rule #1, verdict = pass
Jul 17 19:13:35 (1689614015.983148) danted[804]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 172.18.0.1.50883 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.983159) danted[804]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against host/domain-name mozilla.cloudflare-dns.com.443 for protocol tcp, without alias
Jul 17 19:13:35 (1689614015.983143) danted[792]: debug: addchild(): created new request-child with pid 857, data-pipe 22 and ack-pipe 55.  Minimum rcvbuf: 39160, set: 78320 and 78320.  Minimum sndbuf: 39160, set: 78320 and 78320
Jul 17 19:13:35 (1689614015.983171) danted[792]: debug: childcheck(): added child, pid 857
Jul 17 19:13:35 (1689614015.983180) danted[804]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.983185) danted[804]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.983188) danted[804]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.983195) danted[804]: debug: accesscheck(): method: none, 172.18.0.1.50883 -> 172.18.0.4.1080 
Jul 17 19:13:35 (1689614015.983198) danted[804]: debug: methodisset(): checking if method none is set in the list (1) "none"
Jul 17 19:13:35 (1689614015.983201) danted[804]: debug: accesscheck(): method none already checked, matches
Jul 17 19:13:35 (1689614015.983207) danted[804]: debug: rulespermit(): rule matched: 1 (socks-rule), verdict pass
Jul 17 19:13:35 (1689614015.983217) danted[804]: debug: dorequest(): client requested target mozilla.cloudflare-dns.com.443, we will use 172.64.41.4.443
Jul 17 19:13:35 (1689614015.983233) danted[804]: debug: rule_inheritoruse(): from-rule before (cinfo: 172.18.0.1.50883): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.983243) danted[804]: debug: rule_inheritoruse(): to-rule before (cinfo: 172.18.0.1.50883): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.983248) danted[804]: debug: rule_inheritoruse(): no session settings in client-rule #2 to consider for inheritance
Jul 17 19:13:35 (1689614015.983251) danted[804]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:35 (1689614015.983253) danted[804]: debug: rule_inheritoruse(): no bandwidth settings in client-rule #2 to consider for inheritance
Jul 17 19:13:35 (1689614015.983255) danted[804]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:35 (1689614015.983259) danted[804]: debug: alarm_inherit: sidesconnected: 1
Jul 17 19:13:35 (1689614015.983262) danted[804]: debug: alarm_inherit: from-rule: shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.983265) danted[804]: debug: alarm_inherit: to-rule: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.983268) danted[804]: debug: rule_inheritoruse(): no mstats settings in client-rule #2 to consider for inheritance
Jul 17 19:13:35 (1689614015.983270) danted[804]: debug: rule_inheritoruse(): unuse_from? no  use_to? no
Jul 17 19:13:35 (1689614015.983272) danted[804]: debug: rule_inheritoruse(): from-rule after: shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.983275) danted[804]: debug: rule_inheritoruse(): to-rule after: shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.983261) danted[857]: debug: postconfigloadinit(): I am a request-child
Jul 17 19:13:35 (1689614015.983291) danted[804]: debug: bindexternaladdr(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 172.64.41.4.443, authmethod 0
Jul 17 19:13:35 (1689614015.983297) danted[804]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 172.64.41.4.443, authmethod 0
Jul 17 19:13:35 (1689614015.983300) danted[804]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:35 (1689614015.983308) danted[804]: debug: getoutaddr(): client 172.18.0.1.50883, cmd connect, reqhost 172.64.41.4.443, external.rotation = none
Jul 17 19:13:35 (1689614015.983314) danted[804]: debug: getdefaultexternal(): looking for an IPv4 address with scopeid 0/global, ifindex 0
Jul 17 19:13:35 (1689614015.983315) danted[857]: debug: sockd_setcpusettings(): old cpu scheduling policy/priority: other/0, new: other/0
Jul 17 19:13:35 (1689614015.983335) danted[857]: debug: request_postconfigload()
Jul 17 19:13:35 (1689614015.983368) danted[792]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 62
Jul 17 19:13:35 (1689614015.983473) danted[857]: debug: addchild(): I am a new request-child with data-pipe 0 and ack-pipe 7
Jul 17 19:13:35 (1689614015.983517) danted[804]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:35 (1689614015.983529) danted[804]: debug: getdefaultexternal(): matched IPv4 address 10.5.0.2.0
Jul 17 19:13:35 (1689614015.983537) danted[804]: debug: addrindex_on_externallist(): checking if address 10.5.0.2.0 is a configured external address
Jul 17 19:13:35 (1689614015.983544) danted[804]: debug: addrindex_on_externallist(): external address #0: interfacename nordlynx
Jul 17 19:13:35 (1689614015.983555) danted[857]: debug: sockd_print_child_ready_message(): I'm request-child and ready to serve with 1048567 free fds and 1 free slot
Jul 17 19:13:35 (1689614015.983616) danted[804]: debug: int_ifname2sockaddr(): interface nordlynx missing address on index 2 ... skipping
Jul 17 19:13:35 (1689614015.983630) danted[804]: debug: getoutaddr(): local address 10.5.0.2 selected for forwarding from client 172.18.0.1.50883 to 172.64.41.4.443
Jul 17 19:13:35 (1689614015.983646) danted[804]: debug: socks_bind(): trying to bind address 10.5.0.2.50883 on fd 10.  Retries is 0
Jul 17 19:13:35 (1689614015.983661) danted[804]: debug: socks_bind(): bound address 10.5.0.2.50883 on fd 10
Jul 17 19:13:35 (1689614015.983666) danted[804]: debug: bindexternaladdr(): bound address on external side is 10.5.0.2.50883
Jul 17 19:13:35 (1689614015.983671) danted[804]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 8 (in: 8) on the internal side
Jul 17 19:13:35 (1689614015.983678) danted[804]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 6
Jul 17 19:13:35 (1689614015.983684) danted[804]: debug: setsockoptions(): fd 10, type = 1, isclientside = 0
Jul 17 19:13:35 (1689614015.983689) danted[804]: debug: setsockoptions(): 3 options to set
Jul 17 19:13:35 (1689614015.983698) danted[804]: debug: setnonblocking(): fd 10: setsockoptions()
Jul 17 19:13:35 (1689614015.983702) danted[804]: debug: setsockoptions(): buffer sizes for fd 10 are: SO_SNDBUF: 16384, SO_RCVBUF: 87380
Jul 17 19:13:35 (1689614015.983705) danted[804]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 10 (in: 8) on the external side
Jul 17 19:13:35 (1689614015.983708) danted[804]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matching 5 (pre-establishment or any time)
Jul 17 19:13:35 (1689614015.983710) danted[804]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching 5
Jul 17 19:13:35 (1689614015.983717) danted[804]: debug: serverchain(): client 172.18.0.1.50883, auth none, request VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 172.64.41.4.443
Jul 17 19:13:35 (1689614015.983723) danted[804]: debug: getroute(): request: VER: 5 CMD: 1 FLAG: 0 ATYP: 1 address: 172.64.41.4.443, authmethod 0
Jul 17 19:13:35 (1689614015.983726) danted[804]: debug: getroute(): no routes, faking direct route
Jul 17 19:13:35 (1689614015.983728) danted[804]: debug: serverchain(): using direct system calls for fd 10
Jul 17 19:13:35 (1689614015.983765) danted[804]: debug: socks_connecthost(): connect to 172.64.41.4.443 on external/target side from 10.5.0.2.50883, fd 10.  Timeout is 0
Jul 17 19:13:35 (1689614015.983923) danted[804]: debug: socks_connecthost(): connect(2) to 172.64.41.4.443 from 10.5.0.2.50883 on fd 10 returned -1 (Operation now in progress)
Jul 17 19:13:35 (1689614015.983931) danted[804]: debug: socks_connecthost(): connect to 172.64.41.4.443 from 10.5.0.2.50883 on fd 10 in progress (Operation now in progress)
Jul 17 19:13:35 (1689614015.983935) danted[804]: debug: connect to host 172.64.41.4.443 is now in progress
Jul 17 19:13:35 (1689614015.983948) danted[804]: debug: flushio(): io->control.s = fd -1, io->src.s = fd 8, io->dst.s = fd 10
Jul 17 19:13:35 (1689614015.983955) danted[804]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.983960) danted[804]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.984041) danted[804]: debug: socks_freebuffer(): fd 8
Jul 17 19:13:35 (1689614015.984131) danted[792]: debug: main(): selectn() returned 1 (no system error)
Jul 17 19:13:35 (1689614015.984146) danted[792]: debug: trying to receive request from request-child 804
Jul 17 19:13:35 (1689614015.984174) danted[792]: debug: recv_io(): we are mother
Jul 17 19:13:35 (1689614015.984303) danted[792]: debug: sending client 172.18.0.1.50883 to io-child (pid 828 with 30 slots free)
Jul 17 19:13:35 (1689614015.984310) danted[792]: debug: send_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.984314) danted[792]: debug: send_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.984356) danted[792]: debug: handlechildcommand(): command 1 from request-child 804
Jul 17 19:13:35 (1689614015.984361) danted[792]: debug: handlechildcommand(): request-child 804 has freed a TCP slot, now has 1 slot free
Jul 17 19:13:35 (1689614015.984377) danted[792]: debug: childcheck(): counted 16 free request-child slots.  Removing pid 804 which has handled 1 client during 105s
Jul 17 19:13:35 (1689614015.984376) danted[828]: debug: recv_io(): we are child
Jul 17 19:13:35 (1689614015.984382) danted[792]: debug: closechild(): pid = 804, isnormalexit = 1
Jul 17 19:13:35 (1689614015.984445) danted[828]: debug: socks_allocbuffer(): fd 14, stype = 1
Jul 17 19:13:35 (1689614015.984489) danted[792]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 61
Jul 17 19:13:35 (1689614015.984518) danted[828]: debug: socks_allocbuffer(): fd 15, stype = 1
Jul 17 19:13:35 (1689614015.984563) danted[828]: debug: recv_io(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.984568) danted[828]: debug: recv_io(): shmids in socks-rule #1: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_shmid 0 ((nil))
Jul 17 19:13:35 (1689614015.984573) danted[828]: debug: io_updatemonitor(): control-fd -1, src-fd 14, dst-fd 15, protocol tcp, command connect, mstats_shmid 0, at address (nil)
Jul 17 19:13:35 (1689614015.984585) danted[828]: debug: monitormatch(): 172.18.0.1.50883 -> 172.64.41.4.443
Jul 17 19:13:35 (1689614015.984588) danted[828]: debug: io_updatemonitor(): previously matched mstats_shmid 0, now matching monitor #0 with mstats_shmid 0 (same as now) and alarmsconfigured = 0
Jul 17 19:13:35 (1689614015.984591) danted[828]: debug: recv_io(): we are child
Jul 17 19:13:35 (1689614015.984587) danted[804]: debug: run_request(): mother telling us to exit normally when done
Jul 17 19:13:35 (1689614015.984603) danted[828]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Jul 17 19:13:35 (1689614015.984609) danted[828]: debug: getnewios(): received 1 new io, errno = 11 (Resource temporarily unavailable)
Jul 17 19:13:35 (1689614015.984608) danted[804]: debug: sockdexit(): insignal = 0
Jul 17 19:13:35 (1689614015.984615) danted[804]: debug: request-child: shutting down
Jul 17 19:13:35 (1689614015.984835) danted[828]: debug: io_fillset_connectinprogress(): fd 11 marked as still connecting
Jul 17 19:13:35 (1689614015.984870) danted[828]: debug: io_fillset_connectinprogress(): fd 13 marked as still connecting
Jul 17 19:13:35 (1689614015.984878) danted[828]: debug: io_fillset_connectinprogress(): fd 15 marked as still connecting
Jul 17 19:13:35 (1689614015.984882) danted[828]: debug: run_io(): first select; readable/connected?
Jul 17 19:13:35 (1689614015.984887) danted[828]: debug: io_gettimeout(): last_time = 420009, tnow = 420010, last_timeout_isset = 1, last_timeout = 10.999999
Jul 17 19:13:35 (1689614015.984894) danted[828]: debug: io_gettimeout(): timeout for iov #0 is in 9s
Jul 17 19:13:35 (1689614015.984897) danted[828]: debug: io_gettimeout(): timeout for iov #1 is in 29s
Jul 17 19:13:35 (1689614015.984899) danted[828]: debug: io_gettimeout(): timeout for iov #2 is in 30s
Jul 17 19:13:35 (1689614015.985293) danted[792]: debug: sockd_pushsignal(): pushed signal 17 from pid 804.  Number of signals on the stack is now 1
Jul 17 19:13:35 (1689614015.985314) danted[792]: debug: sockd_handledsignals(): signals left on the stack after popping signal 17: 0
Jul 17 19:13:35 (1689614015.985326) danted[792]: debug: SIGCHLD [: processing signal 17
Jul 17 19:13:35 (1689614015.985364) danted[792]: debug: sigchld(): process 804 exited
Jul 17 19:13:35 (1689614015.985372) danted[792]: debug: sigchld(): request-child-child 804 exiting after 105s and 1 client
Jul 17 19:13:35 (1689614015.985378) danted[792]: debug: resource usage for request-child-child 804
Jul 17 19:13:35 (1689614015.985384) danted[792]: debug: removechild(): pid = 804
Jul 17 19:13:35 (1689614015.985393) danted[792]: debug: SIGCHLD ]: finished processing signal 17
Jul 17 19:13:35 (1689614015.985433) danted[792]: debug: main(): selectn() returned -1 (Interrupted system call)
Jul 17 19:13:35 (1689614015.985479) danted[792]: debug: calling select().  Free negc: 192, reqc: 16, ioc: 61
Jul 17 19:13:41 (1689614021.718598) danted[828]: debug: io_fillset_connectinprogress(): fd 11 marked as still connecting
Jul 17 19:13:41 (1689614021.718648) danted[828]: debug: io_fillset_connectinprogress(): fd 13 marked as still connecting
Jul 17 19:13:41 (1689614021.718652) danted[828]: debug: io_fillset_connectinprogress(): fd 15 marked as still connecting
Jul 17 19:13:41 (1689614021.718657) danted[828]: debug: io_gettimeout(): last_time = 420010, tnow = 420015, last_timeout_isset = 1, last_timeout = 9.999999
Jul 17 19:13:41 (1689614021.718664) danted[828]: debug: io_gettimeout(): timeout for iov #0 is in 4s
Jul 17 19:13:41 (1689614021.718667) danted[828]: debug: io_gettimeout(): timeout for iov #1 is in 24s
Jul 17 19:13:41 (1689614021.718669) danted[828]: debug: io_gettimeout(): timeout for iov #2 is in 25s
Jul 17 19:13:41 (1689614021.718671) danted[828]: debug: run_io(): second select; what is writable?