Modify

Opened 6 years ago

Closed 6 years ago

Last modified 4 years ago

#11850 closed defect (fixed)

wrong result of getpeername() during uhttpd-action results in wrong REMOTE_ADDR

Reported by: Bastian Bittorf <bittorf@…> Owned by: developers
Priority: response-needed Milestone: Barrier Breaker 14.07
Component: packages Version: Trunk
Keywords: Cc:

Description

we use the 404-error-page of uhttpd,
so via http there are a lot of queries.
for handling them (iptables...) we need
the ip-address, which is wrong sometimes:

looks like a IPv6 localhost, but this is
not the case. no localhost and no ipv6 is
involved. in uhttpd-utils.c this is the snippet
for getting the ip:

getpeername(sock, (struct sockaddr *) &(new->peeraddr), &sl);

version-uhttpd: 38
version-libubox: 2012-05-30-0608d1299546d4af1facc271a090cb2abb8c6105
libc - 0.9.33.2-1
trunk: r32582 on ar71xx / Buffalo WZR-HP-AG300H

a typical log is appended.

Attachments (3)

p3.txt.strange2.txt (103.7 KB) - added by Bastian Bittorf <bittorf@…> 6 years ago.
getpeername sometimes wrong, :: instead if correct IP
p3.txt.strange3.txt (36.2 KB) - added by Bastian Bittorf <bittorf@…> 6 years ago.
only failed ones: fgrep "::" log.txt
uhttpd-getpeername-debug.patch (896 bytes) - added by jow 6 years ago.

Download all attachments as: .zip

Change History (18)

Changed 6 years ago by Bastian Bittorf <bittorf@…>

getpeername sometimes wrong, :: instead if correct IP

comment:1 Changed 6 years ago by Bastian Bittorf <bittorf@…>

the wrong address is

::

(wiki syntax eat it, sorry)

comment:2 Changed 6 years ago by jow

These log messages are not produced by uhttpd. What is the code of the program producing them?
To me it looks like it truncates "::ffff:127.0.0.1" to "::" - this would be no uhttpd problem.

comment:3 Changed 6 years ago by jow

  • Priority changed from normal to response-needed

comment:4 Changed 6 years ago by jow

Those "::" entries originate from Microsoft NCSI, the network connectivity check. If it fails to retrieve its expected textfile it does a nslookup on "dns.msftncsi.com" which serves AAAA records, therfore I assume the connectivity check client indeed initiates an IPv6 connection and your logging program simply fails to handle IPv6 mapped IPv4 addresses correctly.

comment:5 Changed 6 years ago by Bastian Bittorf <bittorf@…>

its more complicated. attached is a

fgrep :: log.txt

here you can see, that a lot of other requests have also this issue, not only "Microsoft NCSI". the logging is done is this line, there is _no_ change of the variables REMOTE_ADDR etc. before, just plain logging.

/bin/busybox logger "$0: ERROR${ERROR} for IP '$REMOTE_ADDR' with HTTP_HOST/USER_AGENT: '$HTTP_HOST'/'$HTTP_USER_AGENT'"

also:
if there would be a "::ffff:127.0.0.1" this should be a fundamental errors,
because the request are from LAN.

Changed 6 years ago by Bastian Bittorf <bittorf@…>

only failed ones: fgrep "::" log.txt

comment:6 Changed 6 years ago by Bastian Bittorf <bittorf@…>

also: the logging was only introduced to locate the error. the setup to reproduce is simple: make a /www/cgi-bin-404.sh and place in top of it:

#!/bin/sh

case "$REMOTE_ADDR" in
        "::")
               logger "wrong REMOTE_ADDR ::"
        ;;
        *)
               logger "REMOTE_ADDR fine: $REMOTE_ADDR"
        ;;
esac

comment:7 Changed 6 years ago by jow

I am unable to reproduce this here.

comment:8 Changed 6 years ago by Bastian Bittorf <bittorf@…>

the iptables-setup for redirecting the clients is:

# start with an empty ruleset
iptables -t mangle -A PREROUTING -p tcp --dport 80 -j MARK --set-mark 0x11
iptables -t nat -A PREROUTING -i $LANDEV  -m mark --mark 0x11/0xff -j DNAT --to-destination $LANADR

uhttpd-conf:

root@box:~ cat /etc/config/uhttpd
config uhttpd 'main'
        list listen_http '0.0.0.0:80'
        option home '/www'
        option rfc1918_filter '1'
        option max_requests '3'
        option cgi_prefix '/cgi-bin'
        option script_timeout '60'
        option network_timeout '30'
        option tcp_keepalive '1'
        option index_page 'cgi-bin-404.sh'
        option error_page '/cgi-bin-404.sh'
        option config '/etc/httpd.conf'
        option interpreter '.sh=/bin/ash'

comment:9 Changed 6 years ago by Bastian Bittorf <bittorf@…>

i think: it only happens with a lot of different clients, so
not easy to reproduce...

comment:10 Changed 6 years ago by Bastian Bittorf <bittorf@…>

here i do a

set | logger

during a strange "::" ip-address:

Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: DOCUMENT_ROOT='/www'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: GATEWAY_INTERFACE='CGI/1.1'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: HTTP_ACCEPT='*/*'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: HTTP_ACCEPT_ENCODING='identity'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: HTTP_CONNECTION='Keep-Alive'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: HTTP_HOST='au.download.windowsupdate.com'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: HTTP_USER_AGENT='Microsoft BITS/7.5'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: IFS='    
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: '
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: OPTIND='1'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: PATH='/sbin:/usr/sbin:/bin:/usr/bin'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: PPID='17945'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: PS1='\w \$ '
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: PS2='> '
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: PS4='+ '
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: PWD='/www'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: QUERY_STRING=''
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: REDIRECT_STATUS='404'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: REMOTE_ADDR='::'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: REMOTE_HOST='::'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: REMOTE_PORT='0'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: REQUEST_METHOD='GET'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: REQUEST_URI='/msdownload/update/software/secu/2012/06/infopath-x-none_193bff221d203cfdae9599ed0b4cdc6f4cdc9cc6.cab'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: SCRIPT_FILENAME='/www/cgi-bin-404.sh'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: SCRIPT_NAME='/cgi-bin-404.sh'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: SERVER_ADDR='10.10.2.129'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: SERVER_NAME='10.10.2.129'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: SERVER_PORT='80'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: SERVER_PROTOCOL='HTTP/1.1'
Jul 12 19:00:23 IH-ServerraumInet-AP user.notice root: SERVER_SOFTWARE='uHTTPd'

comment:11 Changed 6 years ago by Bastian Bittorf <bittorf@…>

the strange ip-address "::" can also be seen sometimes, even when zram was never activated and we have no memory problems:

root@box:~ free
             total         used         free       shared      buffers
Mem:        126952        26544       100408            0         1904
-/+ buffers:              24640       102312
Swap:            0            0            0

root@box:~ df -h
Filesystem                Size      Used Available Use% Mounted on
rootfs                   28.6M      2.2M     26.4M   8% /
/dev/root                 2.0M      2.0M         0 100% /rom
tmpfs                    62.0M      2.3M     59.7M   4% /tmp
tmpfs                   512.0K         0    512.0K   0% /dev
/dev/mtdblock7           28.6M      2.2M     26.4M   8% /overlay
overlayfs:/overlay       28.6M      2.2M     26.4M   8% /

comment:12 Changed 6 years ago by jow

Apply the patch below, recompile and wait for the problem to occur, paste the resulting logread messages here.

Changed 6 years ago by jow

comment:13 Changed 6 years ago by Bastian Bittorf <bittorf@…>

after applying patch, the error comes again:

root@box:~ lr | fgrep "failed to obtain remote address"
Jul 13 12:24:02 box daemon.err uhttpd[10553]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:24:02 box daemon.err uhttpd[10553]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:24:02 box daemon.err uhttpd[10553]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:24:05 box daemon.err uhttpd[10553]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:24:05 box daemon.err uhttpd[10553]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:24:06 box daemon.err uhttpd[10553]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:26:26 box daemon.err uhttpd[12888]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:32:45 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:33:15 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:33:15 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:34:45 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:35:24 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:35:24 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:35:24 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:35:24 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:36:24 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:36:24 box daemon.err uhttpd[15462]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:38:25 box daemon.err uhttpd[21346]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:38:25 box daemon.err uhttpd[21346]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:47:40 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:47:40 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:48:10 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:48:10 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:48:48 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:49:18 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:49:18 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:49:18 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:49:18 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:49:18 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:49:18 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:49:18 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]
Jul 13 12:49:18 box daemon.err uhttpd[28793]: Client(5) failed to obtain remote address [Transport endpoint is not connected]

full log is at:
http://intercity-vpn.de/files/openwrt/uhttpd_error.txt

comment:14 Changed 6 years ago by jow

  • Resolution set to fixed
  • Status changed from new to closed

Should be fixed with r32704, the peer address is now resolved at accept() time so there is no gap between accepting and resolving the peer anymore.

comment:15 Changed 4 years ago by jow

  • Milestone changed from Attitude Adjustment 12.09 to Barrier Breaker 14.07

Milestone Attitude Adjustment 12.09 deleted

Add Comment

Modify Ticket

Action
as closed .
The resolution will be deleted. Next status will be 'reopened'.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.