apr-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Noel Butler <noel.but...@ausics.net>
Subject Re: [VOTE] Release Apache httpd 2.4.4 as GA
Date Fri, 22 Feb 2013 10:37:55 GMT
On Thu, 2013-02-21 at 10:24 +1000, Noel Butler wrote:

> On Wed, 2013-02-20 at 23:56 +0100, Rainer Jung wrote:
> 
> 
> > 
> > That's strange, the additional stderr output
> > 
> > "crypt_r returned NULL"
> > 
> > or
> > 
> > "crypt_r returned '%s'"
> > 
> > is not shown here.
> > 
> 
> 
> Indeed, I'm running :
> LogLevel debug auth_basic:trace8 authn_dbd:trace8
> 
> Briefly ran trace8 globally, but only briefly for obvious reasons, my
> eyes were starting to bleed :)
> 
> 
> > As an alternative one could use strace to check the call to crypt_r and
> 
> 
> strace only shows...
> 
> 29311 gettimeofday({1361405772, 894610}, NULL) = 0
> 29311 poll([{fd=17, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
> 29311 write(17, "*\0\0\0\26SELECT Password FROM users WHERE User
> = ?"..., 46) = 46
> 29311 read(17, "\f\0\0\1\0\1\0\0\0\1\0\1\0\0\0\0\27\0\0\2\3def\0\0\0
> \1?\0\f?\0\0\0\0\0\375\200\0\0\0\0\5\0\0\3\376\0\0\2\0007\0\0\4\3def
> \7members\5users\5users\10Password\10Password\f\10\0\0\1\0\0\375\201
> \20\0\0\0\5\0\0\5\376\0\0\2\0"..., 16384) = 120
> 29311 poll([{fd=17, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
> 29311 poll([{fd=17, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
> 29311 write(17, "\23\0\0\0\27\1\0\0\0\0\1\0\0\0\0\1\375\0\4noel"...,
> 23) = 23
> 29311 read(17, "\1\0\0\1\0017\0\0\2\3def\7members\5users\5users
> \10Password\10Password\f\10\0\0\1\0\0\375\201\20\0\0\0\5\0\0\3\376\0\0
> \2\0m\0\0\4\0\0j$6$xxxxxxxxxxxx\5\0\0\5\376\0\0\2\0"..., 16384) = 195
> 29311 gettimeofday({1361405772, 895721}, NULL) = 0
> 29311 write(8, "[Thu Feb 21 10:16:12.895721 2013] [authn_dbd:trace2]
> [pid 29307:tid 3046349680] mod_authn_dbd.c(178): [client
> fd1d:c01d:1ce::145:59592] Got hashed password '$6$xxxxxxxxxxxxx' for
> user 'noel'\n"..., 281) = 281
> 29311 gettimeofday({1361405772, 895975}, NULL) = 0
> 29311 write(8, "[Thu Feb 21 10:16:12.895975 2013] [authn_dbd:debug]
> [pid 29307:tid 3046349680] mod_authn_dbd.c(199): (70024)passwords do
> not match: [client fd1d:c01d:1ce::145:59592] Call to
> apr_password_validate for user 'noel' and hashed password '$6
> $xxxxxxxxxxx"..., 368) = 368
> 29311 gettimeofday({1361405772, 896212}, NULL) = 0
> 29311 write(8, "[Thu Feb 21 10:16:12.896212 2013] [auth_basic:trace1]
> [pid 29307:tid 3046349680] mod_auth_basic.c(246): [client
> fd1d:c01d:1ce::145:59592] Checking password for user 'noel' using
> provider 'dbd', result: 0\n"..., 204) = 204
> 29311 gettimeofday({1361405772, 896399}, NULL) = 0
> 29311 write(8, "[Thu Feb 21 10:16:12.896399 2013] [auth_basic:error]
> [pid 29307:tid 3046349680] [client fd1d:c01d:1ce::145:59592] AH01617:
> user noel: authentication failure for \"/\": Password Mismatch\n"...,
> 184) = 184
> 29311 gettimeofday({1361405772, 896750}, NULL) = 0
> 29311 read(16, 0x8537248, 8000)         = -1 EAGAIN (Resource
> temporarily unavailable)
> 29311 gettimeofday({1361405772, 896880}, NULL) = 0
> 29311 gettimeofday({1361405772, 896933}, NULL) = 0
> 
> 


I don't know if it offers any insight, but running the same strace
command tonight on 2.4.3 with apru1.4.1
prior to, and what I do not see in apru 1.5.1 output (as per above), but
do see in 2.4.3 and apru1.4.1, is  talking to mysql

8526  close(17)                         = 0
8526  socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 17
8526  connect(17, {sa_family=AF_INET, sin_port=htons(3306),
sin_addr=inet_addr("guilty.IP.removed")}, 16) = 0
8526  fcntl64(17, F_SETFL, O_RDONLY)    = 0
8526  fcntl64(17, F_GETFL)              = 0x2 (flags O_RDWR)
8526  setsockopt(17, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0"...,
8) = 0
8526  setsockopt(17, SOL_SOCKET, SO_SNDTIMEO, "\2003\341\1\0\0\0\0"...,
8) = 0
8526  setsockopt(17, SOL_IP, IP_TOS, [8], 4) = 0
8526  setsockopt(17, SOL_TCP, TCP_NODELAY, [1], 4) = 0
8526  setsockopt(17, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
8526  read(17, "N\0\0\0\n5.5.30-log\0!\v\0\0x'SNlXQl\0\377\367\10\2\0\17
\200\25\0\0\0\0\0\0\0\0\0\0M|J:$B
\0mysql_native_password\0"..., 16384) = 82
8526  brk(0x856e000)                    = 0x856e000
8526  stat64("/usr/share/charsets/Index.xml", {st_dev=makedev(8, 1),
st_ino=1359901, st_mode=S_IFREG|0644, st_n
link=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=40,
st_size=18312, st_atime=2013/02/22-11:56:39, st_mtim
e=2013/01/16-17:35:18, st_ctime=2013/02/06-11:28:28}) = 0
8526  open("/usr/share/charsets/Index.xml", O_RDONLY|O_LARGEFILE) = 18
8526  read(18, "<?xml version='1.0' encoding=\"utf-8\"?>\n\n<charsets
max-id=\"99\">\n\n<copyright>\n  Copyright (c) 2003, 2012,  Oracle
and/or its affiliates. All rights reserved.\n\n  This program is free
software; you can redistribute it and/or modify\n  it under the terms of
the GNU General Public License as published by\n  "..., 18312) = 18312
8526  close(18)                         = 0
8526  futex(0xb73c7c80, FUTEX_WAKE_PRIVATE, 2147483647) = 0
8526  write(17, "Z\0\0\1\r\242\16\0\0\0\0@\10\0\0\0\0\0\0\0\0\0\0\0\0\0
\0\0\0\0\0\0\0\0\0\0DBASEUSERRME\0\24d\234ssg\272=\2i(\t\to\336\351\332
\17\314\261fmembers\0mysql_native_password\0"..., 94) = 94
8526  read(17, "\7\0\0\2\0\0\0\2\0\0\0"..., 16384) = 11
8526  poll([{fd=17, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
8526  write(17, "\1\0\0\0\16"..., 5)    = 5
8526  read(17, "\7\0\0\1\0\0\0\2\0\0\0"..., 16384) = 11
8526  gettimeofday({1361528535, 599942}, NULL) = 0
8526  poll([{fd=17, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
8526  write(17, "*\0\0\0\26SELECT Password FROM users WHERE User
= ?"..., 46) = 46

its almost like 1.5.1 is not talking passing off  to the system crypt,
but I'm only guessing.  I did   -Nau diff on 1.4.1 to 1.5.1 and seems a
mammoth amount of apr_password changes, so I wouldn't have the first
clue where to start looking further, hope that helps.



Mime
View raw message