0
OS: Ubuntu 16.04 Dante-Server 1,4Dante Server unbekannt Socken Version
Erste Probleme nach dante Server-Update. Alle Verbindungsblöcke mit Fehler
error after reading 1 byte in 0 seconds: unknown SOCKS version 22 in client request
Konfigurationsdatei:
logoutput: /var/log/danted.log
debug: 2
internal: eth0 port = 1080
external: eth0
socksmethod: none
clientmethod: none
client pass{
from: 91.238.80.151/32 port 1-65535 to: 0.0.0.0/0
log: error connect
socksmethod: none
}
socks pass{
from: 0.0.0.0/0 to: 0.0.0.0/0
command: bind connect udpassociate
log: error
}
Logausgabe:
ru_msgsnd : 0
ru_msgrcv : 0
ru_nsignals: 0
ru_nvcsw : 4
ru_nivcsw : 0
Feb 17 09:41:23 (1487313683.454413) sockd[3012]: debug: removechild(): pid = 3115
Feb 17 09:41:23 (1487313683.454418) sockd[3012]: debug: SIGCHLD ]: finished processing signal 17
Feb 17 09:41:23 (1487313683.454422) sockd[3012]: debug: main(): selectn() returned -1 (Interrupted system call)
Feb 17 09:41:23 (1487313683.454428) sockd[3012]: debug: calling select(). Free negc: 96, reqc: 16, ioc: 32
Feb 17 09:41:23 (1487313683.454444) sockd[3012]: debug: pre-select: nfds = 58, rset = 0x276e630 (7, 10, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29, 30,
31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 53, 55, 57,), bufrset = (nil)(), buffwset = (nil)(), wset =
(nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.942756) sockd[3012]: debug: post-select returned 1 (errno: no system error) nfds = 58, rset = 0x276e630 (7,), bufrset
= (nil)(), buffwset = (nil)(), wset = (nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.942857) sockd[3012]: debug: main(): selectn() returned 1 (no system error)
Feb 17 09:42:01 (1487313721.942901) sockd[3012]: debug: accepted tcp client 91.238.80.152.25327 on address 192.168.1.66.1080, fd 7
Feb 17 09:42:01 (1487313721.942910) sockd[3012]: debug: sending client 91.238.80.152.25327 to negotiate-child (pid 3116 with 96 slots free)
Feb 17 09:42:01 (1487313721.942916) sockd[3012]: debug: send_client(): buflen = 0
Feb 17 09:42:01 (1487313721.942925) sockd[3012]: debug: send_client(): sending fd 0 (laddr: 192.168.1.66.1080, raddr: 91.238.80.152.25327, protocol
: tcp) on fd 21 ...
Feb 17 09:42:01 (1487313721.942971) sockd[3012]: debug: childcheck(): current # of free negotiate-child slots is 95, configured minimum is 96: need
to add more negotiate-children
Feb 17 09:42:01 (1487313721.942993) sockd[3012]: debug: addchild(): type is negotiate-child
Feb 17 09:42:01 (1487313721.943009) sockd[3012]: debug: setnonblocking(): fd 56: pipe between moter and child
Feb 17 09:42:01 (1487313721.943018) sockd[3012]: debug: setnonblocking(): fd 58: pipe between moter and child
Feb 17 09:42:01 (1487313721.943024) sockd[3012]: debug: setnonblocking(): fd 18: pipe between moter and child
Feb 17 09:42:01 (1487313721.943029) sockd[3012]: debug: setnonblocking(): fd 54: pipe between moter and child
Feb 17 09:42:01 (1487313721.943036) sockd[3012]: debug: sockd_priv(): switching privilege 6 on
Feb 17 09:42:01 (1487313721.942997) sockd[3116]: debug: post-select returned 1 (errno: no system error) nfds = 8, rset = 0x2774660 (0,), bufrset =
0x2776670(), buffwset = (nil)(), wset = (nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.943042) sockd[3012]: debug: sockd_setugid(): old uid/gid: 1002/1003, new: 0/0
Feb 17 09:42:01 (1487313721.943092) sockd[3012]: debug: sockd_priv(): switching privilege 6 off
Feb 17 09:42:01 (1487313721.943100) sockd[3012]: debug: sockd_setugid(): old uid/gid: 0/0, new: 1002/1003
Feb 17 09:42:01 (1487313721.943109) sockd[3012]: debug: sockd_priv(): switching privilege 6 on
Feb 17 09:42:01 (1487313721.943113) sockd[3116]: debug: recv_negotiate(): received fd 10 (laddr: 192.168.1.66.1080, raddr: 91.238.80.152.25327, pro
tocol: tcp) ...
Feb 17 09:42:01 (1487313721.943114) sockd[3012]: debug: sockd_setugid(): old uid/gid: 1002/1003, new: 0/0
Feb 17 09:42:01 (1487313721.943137) sockd[3012]: debug: sockd_priv(): switching privilege 6 off
Feb 17 09:42:01 (1487313721.943137) sockd[3116]: debug: rulespermit(): 91.238.80.152.25327 -> 192.168.1.66.1080, clientauth N/A, srcauth notset, co
mmand accept, fd 10 from 91.238.80.152.25327, accepted on 192.168.1.66.1080
Feb 17 09:42:01 (1487313721.943144) sockd[3012]: debug: sockd_setugid(): old uid/gid: 0/0, new: 1002/1003
Feb 17 09:42:01 (1487313721.943152) sockd[3116]: debug: rulespermit(): trying to match against client-rule-rule #1, verdict = pass
Feb 17 09:42:01 (1487313721.943158) sockd[3012]: debug: addchild(): highest fd in use at the moment: 58
Feb 17 09:42:01 (1487313721.943168) sockd[3116]: debug: addrmatch(): matching ruleaddress IPv4 address 192.168.1.1/32 port range 1 - 65535 against
IPv4 address 91.238.80.152.25327 for protocol tcp, without alias
Feb 17 09:42:01 (1487313721.943181) sockd[3116]: debug: rulespermit(): trying to match against client-rule-rule #2, verdict = pass
Feb 17 09:42:01 (1487313721.943189) sockd[3116]: debug: addrmatch(): matching ruleaddress IPv4 address 91.238.80.152/32 port range 1 - 65535 agains
t IPv4 address 91.238.80.152.25327 for protocol tcp, without alias
Feb 17 09:42:01 (1487313721.943198) sockd[3116]: debug: addrmatch(): matching ruleaddress IPv4 address 0.0.0.0/0 against IPv4 address 192.168.1.66.
1080 for protocol tcp, without alias
Feb 17 09:42:01 (1487313721.943205) sockd[3116]: debug: methodisset(): checking if method notset is set in the list (1) "none"
Feb 17 09:42:01 (1487313721.943212) sockd[3116]: debug: rulespermit(): no match yet for method none, command accept
Feb 17 09:42:01 (1487313721.943216) sockd[3116]: debug: rulespermit(): changing authmethod from -1 to 0
Feb 17 09:42:01 (1487313721.943223) sockd[3116]: debug: methodisset(): checking if method none is set in the list (1) "none"
Feb 17 09:42:01 (1487313721.943231) sockd[3116]: debug: accesscheck(): method: none, 91.238.80.152.25327 -> 192.168.1.66.1080
Feb 17 09:42:01 (1487313721.943238) sockd[3116]: debug: methodisset(): checking if method none is set in the list (0) ""
Feb 17 09:42:01 (1487313721.943242) sockd[3116]: debug: methodisset(): checking if method none is set in the list (0) ""
Feb 17 09:42:01 (1487313721.943248) sockd[3116]: debug: accesscheck(): authentication matched
Feb 17 09:42:01 (1487313721.943255) sockd[3116]: debug: rulespermit(): rule matched: 2 (client-rule), verdict pass
Feb 17 09:42:01 (1487313721.943262) sockd[3116]: debug: setconfsockoptions(): going through options, looking for tcp socket options for fd 10 (in:
10) on the internal side
Feb 17 09:42:01 (1487313721.943269) sockd[3116]: debug: setconfsockoptions(): going through global array with 0 options, looking for globals matchi
ng 6 (post-establishment or any time)
Feb 17 09:42:01 (1487313721.943276) sockd[3116]: debug: setconfsockoptions(): going through local array with 0 options, looking for locals matching
6
Feb 17 09:42:01 (1487313721.943288) sockd[3116]: debug: shmem_userule(): cinfo: 91.238.80.152.25327
Feb 17 09:42:01 (1487313721.943295) sockd[3116]: debug: shmem_userule(): shmids in client-rule #2: bw_shmid 0 ((nil)), mstats_shmid 0 ((nil)), ss_s
hmid 0 ((nil))
Feb 17 09:42:01 (1487313721.943310) sockd[3116]: info: pass(2): tcp/accept [: 91.238.80.152.25327 192.168.1.66.1080
Feb 17 09:42:01 (1487313721.943325) sockd[3116]: debug: socks_allocbuffer(): fd 10, stype = 1
Feb 17 09:42:01 (1487313721.943442) sockd[3116]: debug: recvmsgn(): recvmsg() on fd 0 failed, received -1 bytes: Resource temporarily unavailable
Feb 17 09:42:01 (1487313721.943450) sockd[3116]: debug: recv_negotiate(): recvmsg() from mother returned -1 after having received 1 new clients (0
failed/blocked clients). errno = 11 (Resource temporarily unavailable)
Feb 17 09:42:01 (1487313721.943466) sockd[3116]: debug: pre-select: nfds = 11, rset = 0x2774660 (0, 7, 10,), bufrset = 0x2776670 (10,), buffwset
= (nil)(), wset = (nil)(), xset = (nil)(), timeout = 30.999999000s
Feb 17 09:42:01 (1487313721.943476) sockd[3116]: debug: post-select returned 1 (errno: no system error) nfds = 11, rset = 0x2774660 (10,), bufrset
= 0x2776670(), buffwset = (nil)(), wset = (nil)(), xset = (nil)(), timeout = 30.999999000s
Feb 17 09:42:01 (1487313721.943484) sockd[3116]: debug: recv_clientrequest(): fd 10, client 91.238.80.152.25327, state->complete: 0, read so far: 0
Feb 17 09:42:01 (1487313721.943449) sockd[3124]: debug: postconfigloadinit(): I am a negotiate-child
Feb 17 09:42:01 (1487313721.943495) sockd[3116]: debug: socks_recvfrom(): fd 10, len 1, flags 0
Feb 17 09:42:01 (1487313721.943517) sockd[3116]: debug: socks_getfrombuffer(): fd = 10, get up to 1 decoded byte from read buffer which currently h
as 0 decoded, 0 encoded. Flags = 0
Feb 17 09:42:01 (1487313721.943524) sockd[3116]: debug: socks_freeinbuffer(): fd 10, which 0, free: 288
Feb 17 09:42:01 (1487313721.943529) sockd[3116]: debug: socks_freeinbuffer(): fd 10, which 0, free: 288
Feb 17 09:42:01 (1487313721.943524) sockd[3124]: debug: sockd_setcpusettings(): old cpu scheduling policy/priority: other/0, new: other/0
Feb 17 09:42:01 (1487313721.943540) sockd[3116]: debug: socks_recvfrom(): read 207/288 bytes from socket, fd 10, errno = 0 (no system error)
Feb 17 09:42:01 (1487313721.943548) sockd[3116]: debug: socks_freeinbuffer(): fd 10, which 0, free: 288
Feb 17 09:42:01 (1487313721.943554) sockd[3124]: debug: negotiate_postconfigload()
Feb 17 09:42:01 (1487313721.943553) sockd[3116]: debug: socks_addtobuffer(): fd = 10, add 206 unencoded bytes to read buffer which currently has 0
unencoded, 0 encoded. Last bytes to add: 0x1, 0x1. Data will be added after byte 0x0 which is at offset -1
Feb 17 09:42:01 (1487313721.943568) sockd[3116]: debug: run_negotiate(): recv_clientrequest() from client 91.238.80.152.25327 returned 1, errno is
0 (no error)
Feb 17 09:42:01 (1487313721.943582) sockd[3116]: info: block(2): tcp/accept ]: 91.238.80.152.25327 192.168.1.66.1080: error after reading 1 byte in
0 seconds: unknown SOCKS version 22 in client request
Feb 17 09:42:01 (1487313721.943589) sockd[3116]: debug: delete_negotiate(): forwardedtomother: 0
Feb 17 09:42:01 (1487313721.943599) sockd[3116]: debug: socks_sendto(): fd 7, len 1, flags 0, to = NULL
Feb 17 09:42:01 (1487313721.943610) sockd[3116]: debug: socks_freebuffer(): fd 10
Feb 17 09:42:01 (1487313721.943615) sockd[3116]: debug: socks_freebuffer(): freeing buffer with data (206/0, 0/0)
Feb 17 09:42:01 (1487313721.943644) sockd[3116]: debug: pre-select: nfds = 8, rset = 0x2774660 (0, 7,), bufrset = 0x2776670(), buffwset = (nil) (
), wset = (nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.943677) sockd[3124]: debug: addchild(): I am a new negotiate-child with data-pipe 0 and ack-pipe 7
Feb 17 09:42:01 (1487313721.944159) sockd[3012]: debug: addchild(): created new negotiate-child with pid 3124, data-pipe 18 and ack-pipe 56. Minim
um rcvbuf: 23128, set: 46256 and 46256. Minimum sndbuf: 2220288, set: 4440576 and 4440576
Feb 17 09:42:01 (1487313721.944174) sockd[3012]: debug: childcheck(): added child, pid 3124
Feb 17 09:42:01 (1487313721.944210) sockd[3012]: debug: calling select(). Free negc: 191, reqc: 16, ioc: 32
Feb 17 09:42:01 (1487313721.944258) sockd[3012]: debug: pre-select: nfds = 58, rset = 0x276e630 (7, 10, 18, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29,
30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 53, 55, 56, 57,), bufrset = (nil)(), buffwset = (nil)()
, wset = (nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.944299) sockd[3012]: debug: post-select returned 1 (errno: no system error) nfds = 58, rset = 0x276e630 (57,), bufrset
= (nil)(), buffwset = (nil)(), wset = (nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.944307) sockd[3012]: debug: main(): selectn() returned 1 (no system error)
Feb 17 09:42:01 (1487313721.944325) sockd[3012]: debug: socks_recvfrom(): fd 57, len 1, flags 0
Feb 17 09:42:01 (1487313721.944337) sockd[3012]: debug: handlechildcommand(): command 1 from negotiate-child 3116
Feb 17 09:42:01 (1487313721.944343) sockd[3012]: debug: handlechildcommand(): negotiate-child 3116 has freed a TCP slot, now has 96 slots free
Feb 17 09:42:01 (1487313721.944350) sockd[3012]: debug: childcheck(): counted 96 free negotiate-child slots. Removing pid 3116 which has handled 1
client during 97s
Feb 17 09:42:01 (1487313721.944357) sockd[3012]: debug: closechild(): pid = 3116, isnormalexit = 1
Feb 17 09:42:01 (1487313721.944375) sockd[3116]: debug: post-select returned 1 (errno: no system error) nfds = 8, rset = 0x2774660 (7,), bufrset =
0x2776670(), buffwset = (nil)(), wset = (nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.944376) sockd[3012]: debug: calling select(). Free negc: 96, reqc: 16, ioc: 32
Feb 17 09:42:01 (1487313721.944389) sockd[3116]: debug: run_negotiate(): mother telling us to exit normally when done
Feb 17 09:42:01 (1487313721.944401) sockd[3116]: debug: sockdexit(): insignal = 0
Feb 17 09:42:01 (1487313721.944408) sockd[3116]: debug: negotiate-child: shutting down
Feb 17 09:42:01 (1487313721.944411) sockd[3012]: debug: pre-select: nfds = 57, rset = 0x276e630 (7, 10, 18, 20, 22, 23, 24, 25, 26, 27, 28, 29, 30,
31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 53, 55, 56,), bufrset = (nil)(), buffwset = (nil)(), wset =
(nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.944477) sockd[3124]: debug: sockd_print_child_ready_message(): I'm negotiate-child and ready to serve with 65525 free f
ds and 96 free slots
Feb 17 09:42:01 (1487313721.944533) sockd[3124]: debug: pre-select: nfds = 8, rset = 0x2774660 (0, 7,), bufrset = 0x2776670(), buffwset = (nil) (
), wset = (nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.944646) sockd[3012]: debug: sockd_pushsignal(): pushed signal 17 from pid 3116. Number of signals on the stack is now
1
Feb 17 09:42:01 (1487313721.944675) sockd[3012]: debug: post-select returned -1 (errno: Interrupted system call) nfds = 57, rset = 0x276e630 (7, 10
, 18, 20, 22, 23, 24, 25, 26, 27, 28, 29, 30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 53, 55, 56,), bu
frset = (nil)(), buffwset = (nil)(), wset = (nil)(), xset = (nil)(), timeout = 0x0
Feb 17 09:42:01 (1487313721.944683) sockd[3012]: debug: sockd_handledsignals(): signal #1 on the stack is signal 17
Feb 17 09:42:01 (1487313721.944688) sockd[3012]: debug: sockd_handledsignals(): signals left on the stack after popping signal 17: 0
Feb 17 09:42:01 (1487313721.944694) sockd[3012]: debug: SIGCHLD [: processing signal 17
Feb 17 09:42:01 (1487313721.944710) sockd[3012]: debug: sigchld(): process 3116 exited
Feb 17 09:42:01 (1487313721.944717) sockd[3012]: debug: sigchld(): negotiate-child-child 3116 exiting after 97s and 1 client
Feb 17 09:42:01 (1487313721.944724) sockd[3012]: debug: resource usage for negotiate-child-child 3116
ru_utime : 0.000000s
ru_stime : 0.000000s
ru_minflt : 197
ru_majflt : 0
ru_nswap : 0
ru_inblock : 0
ru_oublock : 16
ru_msgsnd : 0
ru_msgrcv : 0
ru_nsignals: 0
ru_nvcsw : 3
ru_nivcsw : 0
Feb 17 09:42:01 (1487313721.944733) sockd[3012]: debug: removechild(): pid = 3116
Feb 17 09:42:01 (1487313721.944739) sockd[3012]: debug: SIGCHLD ]: finished processing signal 17
Feb 17 09:42:01 (1487313721.944744) sockd[3012]: debug: main(): selectn() returned -1 (Interrupted system call)
Feb 17 09:42:01 (1487313721.944761) sockd[3012]: debug: calling select(). Free negc: 96, reqc: 16, ioc: 32
Feb 17 09:42:01 (1487313721.944782) sockd[3012]: debug: pre-select: nfds = 57, rset = 0x276e630 (7, 10, 18, 20, 22, 23, 24, 25, 26, 27, 28, 29, 30,
31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 53, 55, 56,), bufrset = (nil)(), buffwset = (nil)(), wset =
(nil)(), xset = (nil)(), timeout = 0x0
Versuch danted Server aber kein Glück degradieren. Hinzufügen der Regel von: 0.0.0.0/0 bis: 0.0.0.0./0 auch nicht helfen.
Connetions vom Server selbst fällt auch mit unbekannten SOCKS Fehler.
Irgendwelche Ideen, warum das passiert?