On 18/11/2020 15:41, Eric Robinson wrote:
>> -----Original Message-----
>> From: Mark Thomas <ma...@apache.org>
>> Sent: Wednesday, November 18, 2020 3:03 AM
>> To: users@tomcat.apache.org
>> Subject: Re: Weirdest Tomcat Behavior Ever?
>>
>> On 13/11/2020 23:46, Mark Thomas wrote:
>>> Eric sent me a copy of the strace (thanks Eric) and while it is
>>> consistent with what has already been observed, it didn't provide any
>>> new information on the socket / file descriptor being closed.
>>>
>>> I'd like to suggest running again with the following:
>>>
>>> sudo strace -r -f -e trace=network,desc -p <tomcat pid>
>>>
>>> That should log the file descriptor being closed (and other fd
>>> activity). There are a couple of things we might be able to do with this:
>>>
>>> - we'll be able to determine if the socket is closed on the same or a
>>> different thread
>>> - we might be able to correlate the time of closure with other logs
>>> (seems unlikely as we have this from Wireshark but you never know)
>>> - the class before the close might be enlightening
>>
>> Hi Eric,
>>
>> I looked at the updated logs this morning. I don't see any additional logging
>> for file descriptors in the strace output.
>>
>> I wonder if you need a slightly different command on your platform?
>>
>> I'd expect to see entries like this:
>>
>> [pid 8062] 0.000070 openat(AT_FDCWD,
>> "/home/mark/repos/asf-tomcat-master/output/build/webapps/ROOT/bg-
>> nav.png",
>> O_RDONLY) = 57
>> [pid 8062] 0.000027 fstat(57, <unfinished ...>
>> [pid 8062] 0.000005 <... fstat resumed>{st_mode=S_IFREG|0664,
>> st_size=1401, ...}) = 0
>> [pid 8062] 0.000043 read(57, <unfinished ...>
>> [pid 8062] 0.000033 <... read
>> resumed>"\211PNG\r\n\32\n\0\0\0\rIHDR\0\0\0\n\0\0\0002\10\6\0\0\0e\3
>> 3J".
>> resumed>..,
>> 1401) = 1401
>> [pid 8062] 0.000013 close(57 <unfinished ...>
>>
>> showing file access although what I really want to see are the calls to close
>> the sockets (like the last two in the sequence below from a test where I used
>> telnet to perform an HTTP/1.0 request)
>>
>> pid 8069] 0.124099 <... accept resumed>{sa_family=AF_INET6,
>> sin6_port=htons(52656), sin6_flowinfo=htonl(0), inet_pton(AF_INET6,
>> "::ffff:127.0.0.1", &sin6_addr), sin6_scope_id=0}, [28]) = 50 ...
>> [pid 8063] 0.000216 read(50, <unfinished ...>
>> [pid 8063] 0.000058 <... read resumed>"GET / HTTP/1.0\r\n", 8192) = 16
>> [pid 8063] 0.000029 read(50, <unfinished ...>
>> [pid 8063] 0.000030 <... read resumed>0x7f4f6c000e70, 8192) = -1
>> EAGAIN (Resource temporarily unavailable)
>> [pid 8064] 0.001061 read(50, "Host: a\r\n", 8192) = 9
>> [pid 8064] 0.000239 read(50, 0x7f4f60000e70, 8192) = -1 EAGAIN
>> (Resource temporarily unavailable)
>> [pid 8062] 0.000214 read(50, "\r\n", 8192) = 2
>> [pid 8062] 0.007897 write(50, "HTTP/1.1 200 \r\nContent-Type:
>> tex"..., 8192) = 8192
>> [pid 8062] 0.000353 write(50, ">Tomcat Native</a></li>\n
>> "..., 3079) = 3079
>> [pid 8062] 0.002071 getsockopt(50, SOL_SOCKET, SO_LINGER,
>> {l_onoff=0, l_linger=0}, [8]) = 0
>> [pid 8062] 0.000102 shutdown(50, SHUT_WR) = 0
>> [pid 8068] 0.000342 close(50) = 0
>>
>> It is probably worth running a couple of quick tests to figure out the
>> correct
>> form of the strace command on your platform and then retesting.
>>
>> Mark
>>
>
> Entirely my fault. I'm new to strace, so I didn't know what to expect. I have
> now read the strace man page and I'm more up to speed. I tested it and we're
> now capturing file descriptor operations. The next batch of logs will be
> better.
No worries. This strace stuff is new to me as well. I shouldn't have
assumed what worked on my Ubuntu desktop was going to work the same way
on your CentOS server.
I am very curious as to what we are going to see in these logs.
Cheers,
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org
For additional commands, e-mail: users-h...@tomcat.apache.org
