apache24+mod_http2

[02park]

HI ggrandes.
i have some problem.
Cound you help me to slove this problem.

i'm testing apache 2.4(http2) + mod_myfixip
(http2 used mod_http2)

i was finished apache setting and testing to connect HAProxy(proxy protocol) -> apache(http) that is good working.
-->access log printed real client ip
when i was try to connect HAProxy(proxy protocol) -> apache (https +http2)
--> access log print HAProxy ip

i'm guess, may be to affect mod_http2 and mod_myfixip each other.

--- apache debug log ---
HAProxy ip : 1.255.50.178

[Mon Aug 22 14:32:26.296642 2016] [ssl:info] [pid 8369:tid 140405251802880] [client 1.255.50.178:39923] AH01964: Connection to child 4 established (server ncloudy.com:443)
[Mon Aug 22 14:32:26.297066 2016] [ssl:debug] [pid 8369:tid 140405251802880] ssl_engine_kernel.c(2108): [client 1.255.50.178:39923] AH02044: No matching SSL virtual host for servername www.ncloudy.com found (using default/first virtual host)
[Mon Aug 22 14:32:26.297141 2016] [ssl:debug] [pid 8369:tid 140405251802880] ssl_util_stapling.c(754): AH01951: stapling_cb: OCSP Stapling callback called
[Mon Aug 22 14:32:26.297190 2016] [ssl:debug] [pid 8369:tid 140405251802880] ssl_util_stapling.c(762): AH01952: stapling_cb: retrieved cached certificate data
[Mon Aug 22 14:32:26.297256 2016] [socache_shmcb:debug] [pid 8369:tid 140405251802880] mod_socache_shmcb.c(532): AH00835: socache_shmcb_retrieve (0x7e -> subcache 2)
[Mon Aug 22 14:32:26.297280 2016] [socache_shmcb:debug] [pid 8369:tid 140405251802880] mod_socache_shmcb.c(884): AH00849: match at idx=0, data=0
[Mon Aug 22 14:32:26.297288 2016] [socache_shmcb:debug] [pid 8369:tid 140405251802880] mod_socache_shmcb.c(542): AH00836: leaving socache_shmcb_retrieve successfully
[Mon Aug 22 14:32:26.297311 2016] [ssl:debug] [pid 8369:tid 140405251802880] ssl_util_stapling.c(314): AH01933: stapling_get_cached_response: cache hit
[Mon Aug 22 14:32:26.297325 2016] [ssl:debug] [pid 8369:tid 140405251802880] ssl_util_stapling.c(697): AH01953: stapling_cb: retrieved cached response
[Mon Aug 22 14:32:26.297400 2016] [ssl:debug] [pid 8369:tid 140405251802880] ssl_util_stapling.c(813): AH01956: stapling_cb: setting response
[Mon Aug 22 14:32:26.297419 2016] [ssl:debug] [pid 8369:tid 140405251802880] ssl_engine_kernel.c(2108): [client 1.255.50.178:39923] AH02044: No matching SSL virtual host for servername www.ncloudy.com found (using default/first virtual host)
[Mon Aug 22 14:32:26.297436 2016] [core:debug] [pid 8369:tid 140405251802880] protocol.c(1893): [client 1.255.50.178:39923] AH03155: select protocol from h2,h2c,http/1.1, choices=h2,http/1.1 for server ncloudy.com
[Mon Aug 22 14:32:26.297467 2016] [core:debug] [pid 8369:tid 140405251802880] protocol.c(1938): [client 1.255.50.178:39923] AH03156: select protocol, proposals=h2,http/1.1 preferences=h2,h2c,http/1.1 configured=h2,h2c,http/1.1
[Mon Aug 22 14:32:26.297475 2016] [core:debug] [pid 8369:tid 140405251802880] protocol.c(1956): [client 1.255.50.178:39923] AH03157: selected protocol=h2
[Mon Aug 22 14:32:26.309228 2016] [ssl:debug] [pid 8369:tid 140405251802880] ssl_engine_kernel.c(2028): [client 1.255.50.178:39923] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
[Mon Aug 22 14:32:26.309434 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(964): [client 1.255.50.178:39923] AH03200: h2_session(4) created, max_streams=256, stream_mem=262144, workers_limit=4, workers_max=25, push_diary(type=1,N=256)
[Mon Aug 22 14:32:26.309493 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1066): [client 1.255.50.178:39923] AH03201: h2_session(4): start, INITIAL_WINDOW_SIZE=131072, MAX_CONCURRENT_STREAMS=256
[Mon Aug 22 14:32:26.309536 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(2096): [client 1.255.50.178:39923] AH03079: h2_session(4): started on ncloudy.com:443
[Mon Aug 22 14:32:26.309582 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1764): [client 1.255.50.178:39923] AH03078: h2_session(4): transit [INIT] -- init --> [BUSY]
[Mon Aug 22 14:32:26.309656 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(650): [client 1.255.50.178:39923] AH03068: h2_session(4): sent FRAME[SETTINGS[length=12, stream=0]], frames=0/0 (r/s)
[Mon Aug 22 14:32:26.309702 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(650): [client 1.255.50.178:39923] AH03068: h2_session(4): sent FRAME[WINDOW_UPDATE[stream=0, incr=2147352575]], frames=0/1 (r/s)
[Mon Aug 22 14:32:26.309765 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1764): [client 1.255.50.178:39923] AH03078: h2_session(4): transit [BUSY] -- no io --> [IDLE]
[Mon Aug 22 14:32:26.309949 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(423): [client 1.255.50.178:39923] AH03066: h2_session(4): recv FRAME[SETTINGS[length=12, stream=0]], frames=0/2 (r/s)
[Mon Aug 22 14:32:26.310020 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(423): [client 1.255.50.178:39923] AH03066: h2_session(4): recv FRAME[WINDOW_UPDATE[stream=0, incr=15663105]], frames=1/2 (r/s)
[Mon Aug 22 14:32:26.310059 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1764): [client 1.255.50.178:39923] AH03078: h2_session(4): transit [IDLE] -- data read --> [BUSY]
[Mon Aug 22 14:32:26.310098 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(650): [client 1.255.50.178:39923] AH03068: h2_session(4): sent FRAME[SETTINGS[ack=1, stream=0]], frames=2/2 (r/s)
[Mon Aug 22 14:32:26.310154 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1764): [client 1.255.50.178:39923] AH03078: h2_session(4): transit [BUSY] -- no io --> [IDLE]
[Mon Aug 22 14:32:26.310308 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_stream.c(152): [client 1.255.50.178:39923] AH03082: h2_stream(4-1): opened
[Mon Aug 22 14:32:26.310397 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(423): [client 1.255.50.178:39923] AH03066: h2_session(4): recv FRAME[HEADERS[length=285, hend=1, stream=1, eos=1]], frames=2/3 (r/s)
[Mon Aug 22 14:32:26.310582 2016] [ssl:debug] [pid 8369:tid 140405556008704] ssl_engine_kernel.c(366): [client 1.255.50.178:39923] AH02034: Initial (No.1) HTTPS request received for child 4 (server ncloudy.com:443)
[Mon Aug 22 14:32:26.310742 2016] [authz_core:debug] [pid 8369:tid 140405556008704] mod_authz_core.c(809): [client 1.255.50.178:39923] AH01626: authorization result of Require all granted: granted
[Mon Aug 22 14:32:26.310754 2016] [authz_core:debug] [pid 8369:tid 140405556008704] mod_authz_core.c(809): [client 1.255.50.178:39923] AH01626: authorization result of : granted
[Mon Aug 22 14:32:26.311304 2016] [http2:debug] [pid 8369:tid 140405556008704] h2_task_output.c(81): [client 1.255.50.178:39923] AH03348: h2_task(4-1): open response to GET www.ncloudy.com /
[Mon Aug 22 14:32:26.311491 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1764): [client 1.255.50.178:39923] AH03078: h2_session(4): transit [IDLE] -- data read --> [BUSY]
[Mon Aug 22 14:32:26.311558 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1279): [client 1.255.50.178:39923] AH03073: h2_stream(4-1): submit response 304
[Mon Aug 22 14:32:26.311603 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(650): [client 1.255.50.178:39923] AH03068: h2_session(4): sent FRAME[HEADERS[length=83, hend=1, stream=1, eos=0]], frames=3/3 (r/s)
[Mon Aug 22 14:32:26.311646 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(650): [client 1.255.50.178:39923] AH03068: h2_session(4): sent FRAME[DATA[length=0, flags=1, stream=1, padlen=0]], frames=3/4 (r/s)
[Mon Aug 22 14:32:26.311787 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1764): [client 1.255.50.178:39923] AH03078: h2_session(4): transit [BUSY] -- no io --> [IDLE]
[Mon Aug 22 14:32:26.311983 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(423): [client 1.255.50.178:39923] AH03066: h2_session(4): recv FRAME[SETTINGS[ack=1, stream=0]], frames=3/5 (r/s)
[Mon Aug 22 14:32:26.312062 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1764): [client 1.255.50.178:39923] AH03078: h2_session(4): transit [IDLE] -- data read --> [BUSY]
[Mon Aug 22 14:32:26.312116 2016] [http2:debug] [pid 8369:tid 140405251802880] h2_session.c(1764): [client 1.255.50.178:39923] AH03078: h2_session(4): transit [BUSY] -- no io --> [IDLE]

[02park]

i was test conneted http1.1 (HAProxy -> apache) than acess log printed real client ip

[ggrandes]

you have sample conf to reproduce in my test environment?

[02park]

My test ecnvironment --> apache conf
please let me know if you need additional information.

--- this is httpd.conf ---

ServerRoot "/home/test/server/httpd2"
Listen 80
LoadModule access_compat_module modules/mod_access_compat.so
LoadModule alias_module modules/mod_alias.so
LoadModule auth_basic_module modules/mod_auth_basic.so
LoadModule authn_core_module modules/mod_authn_core.so
LoadModule authn_file_module modules/mod_authn_file.so
LoadModule authz_core_module modules/mod_authz_core.so
LoadModule authz_groupfile_module modules/mod_authz_groupfile.so
LoadModule authz_host_module modules/mod_authz_host.so
LoadModule authz_user_module modules/mod_authz_user.so
LoadModule autoindex_module modules/mod_autoindex.so
LoadModule deflate_module modules/mod_deflate.so
LoadModule dir_module modules/mod_dir.so
LoadModule env_module modules/mod_env.so
LoadModule expires_module modules/mod_expires.so
LoadModule filter_module modules/mod_filter.so
LoadModule headers_module modules/mod_headers.so
LoadModule http2_module modules/mod_http2.so
LoadModule log_config_module modules/mod_log_config.so
LoadModule mime_module modules/mod_mime.so
LoadModule remoteip_module modules/mod_remoteip.so
LoadModule rewrite_module modules/mod_rewrite.so
LoadModule setenvif_module modules/mod_setenvif.so
LoadModule slotmem_shm_module modules/mod_slotmem_shm.so
LoadModule socache_dbm_module modules/mod_socache_dbm.so
LoadModule socache_shmcb_module modules/mod_socache_shmcb.so
LoadModule ssl_module modules/mod_ssl.so
LoadModule status_module modules/mod_status.so
LoadModule unixd_module modules/mod_unixd.so
LoadModule version_module modules/mod_version.so
LoadModule allowmethods_module modules/mod_allowmethods.so
#LoadModule unique_id_module modules/mod_unique_id.so
LoadModule vhost_alias_module modules/mod_vhost_alias.so
LoadModule negotiation_module modules/mod_negotiation.so
LoadModule proxy_module modules/mod_proxy.so
LoadModule proxy_http_module modules/mod_proxy_http.so

LoadModule myfixip_module modules/mod_myfixip.so
LoadModule proxy_protocol_module modules/mod_proxy_protocol.so

RewriteIPResetHeader off RewriteIPAllow 1.255.0.0/16 127.0.0.1 User test Group test ServerAdmin root@localhost

ServerName www.ncloudy.com
HostnameLookups Off
ServerSignature Off
TraceEnable Off
FileETag MTime Size

Options FollowSymLinks AllowOverride None Require all granted

DocumentRoot "/home/test/server/httpd2/htdocs"

DirectoryIndex index.html

<FilesMatch "^.ht">
Order allow,deny
Deny from all
Satisfy All

ErrorLog "logs/error_log"

LogLevel debug

LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined LogFormat "%h %l %u %t \"%r\" %>s %b" common LogFormat "%a %h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" \"%{Cookie}i\" %D" combined2

<IfModule logio_module>
  LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %I %O" combinedio
</IfModule>

ScriptAlias /cgi-bin/ "/home/test/server/httpd2/cgi-bin/" TypesConfig conf/mime.types

AddType application/x-compress .Z
AddType application/x-gzip .gz .tgz

Include conf/extra/proxy-html.conf

Include conf/extra/test-ssl.conf

SSLRandomSeed startup builtin
SSLRandomSeed connect builtin

HTTP 2.0 for http, https server

Protocols h2 h2c http/1.1

H2Direct on
H2Push on
H2Upgrade on
H2MaxSessionStreams 256
H2MaxWorkerIdleSeconds 60
H2StreamMaxMemSize 262144
H2WindowSize 131072

Header Size limite

LimitRequestLine 1024

ListenBacklog 1023

CustomLog logs/access.log "%a %l %u %t "%r" %>s %b "%{Referer}i" "%{User-agent}i""

--- this is test-ssl.conf ---
Listen 443

AddType application/x-x509-ca-cert .crt
AddType application/x-pkcs7-crl .crl

SSLPassPhraseDialog builtin
SSLSessionCache "shmcb:/home/test/server/httpd2/logs/ssl_scache(512000)"
SSLSessionCacheTimeout 300

SSLUseStapling on
SSLStaplingResponderTimeout 5
SSLStaplingReturnResponderErrors off
SSLStaplingCache shmcb:/var/run/ocsp(128000)

SSLProtocol All -SSLv2 -SSLv3
SSLHonorCipherOrder On
SSLCipherSuite "kEDH+AESGCM:DHE-DSS-AES256-SHA:EECDH:RSA+AES:EDH+aRSA:!aNULL:!eNULL:!LOW:!DES:!3DES:!MD5:!EXPORT:!PSK:!SRP:!RC4:!ECDHE-RSA-AES256-SHA"

<VirtualHost *:443>
DocumentRoot "/home/test/server/httpd2/htdocs"
ServerName www.ncloudy.com

<IfModule mod_myfixip.c>
    RewriteIPResetHeader on
</IfModule>

SSLEngine on
SSLCertificateFile "conf/ssl/star_ncloudy_com_cert.pem"
SSLCertificateKeyFile "conf/ssl/key.pem"
SSLCACertificateFile "conf/ssl/Chain_RootCA_Bundle.crt"

CustomLog logs/ssl-access.log "%a %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-agent}i\""

Options FollowSymLinks AllowOverride None Require all granted