NetBSD-Users archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]

Re: Upgrade from 7.0.2 to 8.0_BETA: some trouble with sockets (I think)

BERTRAND Joël a écrit :

Manuel Bouyer a écrit :

On Mon, Jul 03, 2017 at 11:25:38AM +0200, BERTRAND Joël wrote:

Manuel Bouyer a écrit :

On Sun, Jul 02, 2017 at 03:55:39PM +0200, BERTRAND Joël wrote:

Can you ktrace the mysql daemon while doint this ?
Eventually match the tcpdump timestamps with the kdump one, to see
exaclty
what cause the socket to be closed, and what is happening before.


I have ktrace'd mysqld process before posting here (only when I try
to open
a new connection from client). I paste an extraction of this file :


Are you sure you got all the related informations ?
this is where mayching timestamps from tcpdump with timestamps from
kdump -T would help


    Very strange :

On client side (linux box, amd64):
$  mysql -uzmuser -p -hlegendre
Enter password:
ERROR 2013 (HY000): Lost connection to MySQL server at 'reading initial
communication packet', system error: 104 "Connection reset by peer"

On server side:
legendre# tcpdump -tt -i agr0 port 3306
tcpdump: verbose output suppressed, use -v or -vv for full protocol
decode
listening on agr0, link-type EN10MB (Ethernet), capture size 262144
bytes
1499073569.026306 IP 192.168.10.103.59532 > 192.168.10.128.mysql:
Flags [S],
seq 688000445, win 29200, options [mss 1460,sackOK,TS val 44791111 ecr
0,nop,wscale 7], length 0
1499073569.026337 IP 192.168.10.128.mysql > 192.168.10.103.59532: Flags
[S.], seq 2439021135, ack 688000446, win 32768, options [mss
1460,nop,wscale
3,sackOK,TS val 1 ecr 44791111], length 0
1499073569.026440 IP 192.168.10.103.59532 > 192.168.10.128.mysql:
Flags [.],
ack 1, win 229, options [nop,nop,TS val 44791111 ecr 1], length 0
1499073569.026473 IP 192.168.10.128.mysql > 192.168.10.103.59532:
Flags [R],
seq 2439021136, win 0, length 0

But kdump -T doesn't show any similar timestamp :

 14288     13 mysqld   1499073568.381466253 RET   ___lwp_park60 -1
errno 60
Connection timed out
 14288     13 mysqld   1499073568.381469810 CALL
__gettimeofday50(0x79f65fdffe60,0)
 14288     13 mysqld   1499073568.381470435 RET   __gettimeofday50 0
 14288     13 mysqld   1499073568.381472191 CALL
___lwp_park60(0,1,0x79f65fdffed0,0,0x79f663df2198,0x79f663df2198)
 14288     14 mysqld   1499073568.413143778 RET   ___lwp_park60 -1
errno 60
Connection timed out
 14288     14 mysqld   1499073568.413149847 CALL
__gettimeofday50(0x79f65f9feef0,0)
 14288     14 mysqld   1499073568.413150487 RET   __gettimeofday50 0
 14288     14 mysqld   1499073568.413175021 CALL
__gettimeofday50(0x79f65f9fee20,0)
 14288     14 mysqld   1499073568.413175827 RET   __gettimeofday50 0
 14288     14 mysqld   1499073568.413178033 CALL
___lwp_park60(0,1,0x79f65f9fee90,0,0x79f688d17b98,0x79f688d17b98)
 14288     16 mysqld   1499073568.821865058 RET   __select50 0
 14288     16 mysqld   1499073568.821867715 CALL
__gettimeofday50(0x79f65f1fcf70,0)
 14288     16 mysqld   1499073568.821868385 RET   __gettimeofday50 0
 14288     16 mysqld   1499073568.821869736 CALL
__gettimeofday50(0x79f65f1fcf70,0)
 14288     16 mysqld   1499073568.821870302 RET   __gettimeofday50 0
 14288     16 mysqld   1499073568.821872158 CALL
__gettimeofday50(0x79f65f1fcf60,0)
 14288     16 mysqld   1499073568.821872793 RET   __gettimeofday50 0
 14288     16 mysqld   1499073568.821875340 CALL
__select50(0,0,0,0,0x79f65f1fcf70)
 14288     18 mysqld   1499073568.829767482 RET   __select50 0
 14288     18 mysqld   1499073568.829771034 CALL
__gettimeofday50(0x79f6607f5f10,0)
 14288     18 mysqld   1499073568.829771674 RET   __gettimeofday50 0
 14288     18 mysqld   1499073568.829774426 CALL
__gettimeofday50(0x79f6607f5f10,0)

    I don't understand... I suppose ktrace has to show socket activity.


Assuming the socket queue isn't full (netstat -f inet would show this),
does the mysqld listen on the address you're connecting to ?
netstat -a -f inet will show this (or fstat).

Another possibility is a packet filter which is sending the RST


legendre# netstat -a -f inet | grep mysql
legendre# netstat -a -f inet6 | grep mysql
tcp6       0      0  *.mysql                *.*                    LISTEN
legendre#

I don't understand why mysql doesn't listen on ipv4 anymore.
Configuration was not modified between running configuration (NetBSD
7.0.2) and faulty one.

I have check squid and I obtain :
legendre# fstat | grep squid | grep intern
squid    pinger     28605    0* internet6 dgram udp localhost:64928 <->
localhost:64929
squid    pinger     28605    1* internet6 dgram udp localhost:64928 <->
localhost:64929
squid    pinger     28605    3* internet raw icmp fffffe841b1dd1f8
squid    pinger     28605    4* internet6 raw icmp6 fffffe8411ba4000
squid    squid       6805    6* internet6 dgram udp *:64930
squid    squid       6805    8* internet dgram udp *:62672
squid    squid       6805   17* internet6 stream tcp *:ndl-aas
squid    squid       6805   19* internet6 dgram udp localhost:64929 <->
localhost:64928
legendre#

It listens on tcp6 and not on tcp !

    Of course, I've only upgrade NetBSD from a running configuration.

    Best regards,

    JKB



	Some bad news :
If I force http_port 192.168.10.128:3128 (instead of http_port 3128) in squid.conf, squid works as expected in ipv4 : 

legendre# fstat | grep squid | grep intern
squid pinger 1459 0* internet6 dgram udp localhost:63206 <-> localhost:63207 squid pinger 1459 1* internet6 dgram udp localhost:63206 <-> localhost:63207 
squid    pinger      1459    3* internet raw icmp fffffe841b1dd2e8
squid    pinger      1459    4* internet6 raw icmp6 fffffe8411ba4480
squid    squid      19452    9* internet6 dgram udp *:63208
squid    squid      19452   10* internet dgram udp *:54131
squid    squid      19452   19* internet stream tcp 192.168.10.128:ndl-aas
squid squid 19452 21* internet6 dgram udp localhost:63207 <-> localhost:63206 

	I suppose mysqld triggers a similar issue.

	Regards,

	JKB
Home | Main Index | Thread Index | Old Index