tl;dnr
I can not get my docker-compose Envoy API gateway to properly forward to referenced services.
"Forwarded routes" always end up with the error:
upstream connect error or disconnect/reset before headers. reset reason: connection termination
I must have mucked up something simple since this is so difficult to resolve. Any additional assistance would be appreciated.
Apologies for the length, the nitty-gritty!
Hello folks, this is the first time I've attemped to use Envoy as my API gateway, and can not seem to get past the above error. Basically I have two .Net 5 services, tags and docs, inside individual docker containers with their ports exposed. I would like to use Envoy as a simple API gateway (no https yet) just to redirect traffic to the proper service based on a simple route match.
Now, I've been using a number of online examples as the basis for my experiment, so I have had to gone wrong somewhere. Any drection pointing would be greatly appreciated. I have verified all of the following:
curl http://localapp-tags/api/Cats
successfully.Sites I've used as reference or ran locally to base my application's config file[s] on:
After Googling for hours (too many sites/links to list), the most concrete suggestion was to increase the connection_timeout
from .25s to 30secs, this did not make any difference for me. So while I know there seems to be answers out there (and this may be a duplicate), in fact nothing else solved the problem :(
I've also tried to create a named network inside docker-compose (eg. Front-Proxy example, but this did not work either!)
Again, any other suggestions to look into would be appreciated.
So as you can see, I went through a number of tutorials and baby-steps before I came up with my own docker-compose and envoy config files.
docker-compose.yaml (some parts left out for brevity, also disregard spelling errors as I did a search and replace and may have missed something)
# Edge/Api Gateway localapp-gw: image: ${REGISTRY:}/localapp.apigw:${PLATFORM:-linux}-${TAG:-latest} build: context: ./server-conf/envoy ports: - "9901:9901" - "10000:10000" - "10001:10001" - "10080:10080" - "10443:10443" volumes: - ./server-conf/envoy/envoy.yaml:/etc/envoy/envoy.yaml # Backend APIS localapp-tags: image: ${REGISTRY:}/localapp.tags:${PLATFORM:-linux}-${TAG:-latest} build: context: . dockerfile: code/Services/Tag/localapp.tags/Dockerfile environment: - ASPNETCORE_ENVIRONMENT=Development - ASPNETCORE_URLS=http://+:80; - GRPC_PORT=81 - PORT=80 ports: - "32080:80" - "32081:81" - "32443:443" volumes: - ${APPDATA}/Microsoft/UserSecrets:/root/.microsoft/usersecrets:ro - ${USERPROFILE}/.aspnet/https:/root/.aspnet/https:ro localapp-docs: image: ${REGISTRY:}/localapp.docs:${PLATFORM:-linux}-${TAG:-latest} build: context: . dockerfile: code/Services/Document/localapp.docs/Dockerfile environment: - ASPNETCORE_ENVIRONMENT=Development - ASPNETCORE_URLS=http://+:80; - GRPC_PORT=81 - PORT=80 ports: - "36080:80" - "36081:81" - "36443:443" volumes: - ${APPDATA}/Microsoft/UserSecrets:/root/.microsoft/usersecrets:ro - ${USERPROFILE}/.aspnet/https:/root/.aspnet/https:ro
envoy.yaml
admin: access_log_path: /tmp/admin_access.log address: socket_address: address: 0.0.0.0 port_value: 9901 static_resources: listeners: - name: listener_0 address: socket_address: address: 0.0.0.0 port_value: 10000 filter_chains: - filters: - name: envoy.filters.network.http_connection_manager typed_config: "@type": type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager stat_prefix: ingress_http access_log: - name: envoy.access_loggers.file typed_config: "@type": type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog path: /tmp/stdout http_filters: - name: envoy.filters.http.router route_config: name: local_route virtual_hosts: - name: local_service domains: ["*"] routes: - match: prefix: "/" route: host_rewrite_literal: www.envoyproxy.io cluster: service_envoyproxy_io - name: listener_10080 address: socket_address: address: 0.0.0.0 port_value: 10080 filter_chains: - filters: - name: envoy.filters.network.http_connection_manager typed_config: "@type": type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager codec_type: auto stat_prefix: ingress_http route_config: name: onecore_route virtual_hosts: - name: localapp_services domains: ["*"] routes: - match: { prefix: "/t/" } route: cluster: tags_service auto_host_rewrite: true idle_timeout: 10s - match: { prefix: "/d/" } route: cluster: docs_service auto_host_rewrite: true idle_timeout: 10s http_filters: - name: envoy.filters.http.router typed_config: {} clusters: - name: service_envoyproxy_io connect_timeout: 30s type: LOGICAL_DNS dns_lookup_family: V4_ONLY load_assignment: cluster_name: service_envoyproxy_io endpoints: - lb_endpoints: - endpoint: address: socket_address: address: www.envoyproxy.io port_value: 443 transport_socket: name: envoy.transport_sockets.tls typed_config: "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext sni: www.envoyproxy.io - name: tags_service connect_timeout: 30s type: strict_dns lb_policy: round_robin http2_protocol_options: {} load_assignment: cluster_name: tags_service endpoints: - lb_endpoints: - endpoint: address: socket_address: address: localapp-tags port_value: 80 - name: docs_service connect_timeout: 30s type: strict_dns lb_policy: round_robin http2_protocol_options: {} load_assignment: cluster_name: docs_service endpoints: - lb_endpoints: - endpoint: address: socket_address: address: localapp-docs port_value: 80 layered_runtime: layers: - name: static_layer_0 static_layer: envoy: resource_limits: listener: example_listener_name: connection_limit: 10000
So yeah, I'm a bit stuck here trying to figure out what I missed/botched up (but I could just be code blind after these two weeks). The envoy.yaml file was copied from reference material, so I'm just missing something obvious (and hopefully it is not just an ico issue!).
There are a few errors in the tracelog, including the main one above, but I am not yet able to figure out the issue (or to appreciate/understand the tracelog)! Excerpt:
[2021-02-28 10:51:10.705][17][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x1e07bf442380 for 3600000ms, min is 3600000ms [2021-02-28 10:51:10.705][17][debug][conn_handler] [source/server/connection_handler_impl.cc:501] [C2] new connection [2021-02-28 10:51:10.705][17][trace][connection] [source/common/network/connection_impl.cc:548] [C2] socket event: 2 [2021-02-28 10:51:10.705][17][trace][connection] [source/common/network/connection_impl.cc:657] [C2] write ready [2021-02-28 10:51:10.707][17][trace][connection] [source/common/network/connection_impl.cc:548] [C2] socket event: 3 [2021-02-28 10:51:10.707][17][trace][connection] [source/common/network/connection_impl.cc:657] [C2] write ready [2021-02-28 10:51:10.707][17][trace][connection] [source/common/network/connection_impl.cc:586] [C2] read ready. dispatch_buffered_data=false [2021-02-28 10:51:10.707][17][trace][connection] [source/common/network/raw_buffer_socket.cc:25] [C2] read returns: 357 [2021-02-28 10:51:10.707][17][trace][connection] [source/common/network/raw_buffer_socket.cc:39] [C2] read error: Resource temporarily unavailable [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:571] [C2] parsing 357 bytes [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:847] [C2] message begin [2021-02-28 10:51:10.708][17][debug][http] [source/common/http/conn_manager_impl.cc:254] [C2] new stream [2021-02-28 10:51:10.708][17][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x1e07bf442400 for 300000ms, min is 300000ms [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:494] [C2] completed header: key=Host value=host.docker.internal:10080 [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:494] [C2] completed header: key=User-Agent value=Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:85.0) Gecko/20100101 Firefox/85.0 [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:494] [C2] completed header: key=Accept value=text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8 [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:494] [C2] completed header: key=Accept-Language value=en-US,en;q=0.5 [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:494] [C2] completed header: key=Accept-Encoding value=gzip, deflate [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:494] [C2] completed header: key=Connection value=keep-alive [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:699] [C2] onHeadersCompleteBase [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:494] [C2] completed header: key=Upgrade-Insecure-Requests value=1 [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:952] [C2] Server: onHeadersComplete size=7 [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:823] [C2] message complete [2021-02-28 10:51:10.708][17][trace][connection] [source/common/network/connection_impl.cc:346] [C2] readDisable: disable=true disable_count=0 state=0 buffer_length=357 [2021-02-28 10:51:10.708][17][debug][http] [source/common/http/conn_manager_impl.cc:886] [C2][S9636672460028773107] request headers complete (end_stream=true): ':authority', 'host.docker.internal:10080' ':path', '/t/api/Tags' ':method', 'GET' 'user-agent', 'Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:85.0) Gecko/20100101 Firefox/85.0' 'accept', 'text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8' 'accept-language', 'en-US,en;q=0.5' 'accept-encoding', 'gzip, deflate' 'connection', 'keep-alive' 'upgrade-insecure-requests', '1' [2021-02-28 10:51:10.708][17][debug][http] [source/common/http/filter_manager.cc:755] [C2][S9636672460028773107] request end stream [2021-02-28 10:51:10.708][17][debug][router] [source/common/router/router.cc:425] [C2][S9636672460028773107] cluster 'tags_service' match for URL '/t/api/Tags' [2021-02-28 10:51:10.708][17][debug][router] [source/common/router/router.cc:582] [C2][S9636672460028773107] router decoding headers: ':authority', 'host.docker.internal:10080' ':path', '/t/api/Tags' ':method', 'GET' ':scheme', 'http' 'user-agent', 'Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:85.0) Gecko/20100101 Firefox/85.0' 'accept', 'text/html,ap plication/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8' 'accept-language', 'en-US,en;q=0.5' 'accept-encoding', 'gzip, deflate' 'upgrade-insecure-requests', '1' 'x-forwarded-proto', 'http' 'x-request-id', 'd3ddb11a-85bb-479e-a29f-b850439d04aa' 'x-envoy-expected-rq-timeout-ms', '15000' [2021-02-28 10:51:10.708][17][debug][pool] [source/common/http/conn_pool_base.cc:79] queueing stream due to no available connections [2021-02-28 10:51:10.708][17][debug][pool] [source/common/conn_pool/conn_pool_base.cc:106] creating a new connection [2021-02-28 10:51:10.708][17][debug][client] [source/common/http/codec_client.cc:41] [C3] connecting [2021-02-28 10:51:10.708][17][debug][connection] [source/common/network/connection_impl.cc:860] [C3] connecting to 172.18.0.11:80 [2021-02-28 10:51:10.708][17][debug][connection] [source/common/network/connection_impl.cc:876] [C3] connection in progress [2021-02-28 10:51:10.708][17][trace][http2] [source/common/http/http2/codec_impl.cc:1355] Codec does not have Metadata frame support. [2021-02-28 10:51:10.708][17][debug][http2] [source/common/http/http2/codec_impl.cc:1184] [C3] updating connection-level initial window size to 268435456 [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/filter_manager.cc:498] [C2][S9636672460028773107] decode headers called: filter=0x1e07bf442100 status=1 [2021-02-28 10:51:10.708][17][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x1e07bf442400 for 10000ms, min is 10000ms [2021-02-28 10:51:10.708][17][trace][http] [source/common/http/http1/codec_impl.cc:620] [C2] parsed 357 bytes [2021-02-28 10:51:10.708][17][trace][connection] [source/common/network/connection_impl.cc:548] [C2] socket event: 2 [2021-02-28 10:51:10.708][17][trace][connection] [source/common/network/connection_impl.cc:657] [C2] write ready [2021-02-28 10:51:10.708][17][trace][connection] [source/common/network/connection_impl.cc:548] [C3] socket event: 2 [2021-02-28 10:51:10.708][17][trace][connection] [source/common/network/connection_impl.cc:657] [C3] write ready [2021-02-28 10:51:10.708][17][debug][connection] [source/common/network/connection_impl.cc:666] [C3] connected [2021-02-28 10:51:10.708][17][trace][connection] [source/common/network/connection_impl.cc:407] [C3] raising connection event 2 [2021-02-28 10:51:10.708][17][debug][client] [source/common/http/codec_client.cc:80] [C3] connected [2021-02-28 10:51:10.708][17][debug][pool] [source/common/conn_pool/conn_pool_base.cc:225] [C3] attaching to next stream [2021-02-28 10:51:10.708][17][debug][pool] [source/common/conn_pool/conn_pool_base.cc:130] [C3] creating stream [2021-02-28 10:51:10.708][17][debug][router] [source/common/router/upstream_request.cc:354] [C2][S9636672460028773107] pool ready [2021-02-28 10:51:10.708][17][trace][http2] [source/common/http/http2/codec_impl.cc:946] [C3] send data: bytes=24 [2021-02-28 10:51:10.708][17][trace][connection] [source/common/network/connection_impl.cc:465] [C3] writing 24 bytes, end_stream false [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:924] [C3] about to send frame type=4, flags=0 [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:946] [C3] send data: bytes=39 [2021-02-28 10:51:10.709][17][trace][connection] [source/common/network/connection_impl.cc:465] [C3] writing 39 bytes, end_stream false [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:853] [C3] sent frame type=4 [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:924] [C3] about to send frame type=8, flags=0 [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:946] [C3] send data: bytes=13 [2021-02-28 10:51:10.709][17][trace][connection] [source/common/network/connection_impl.cc:465] [C3] writing 13 bytes, end_stream false [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:853] [C3] sent frame type=8 [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:924] [C3] about to send frame type=1, flags=5 [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:946] [C3] send data: bytes=282 [2021-02-28 10:51:10.709][17][trace][connection] [source/common/network/connection_impl.cc:465] [C3] writing 282 bytes, end_stream false [2021-02-28 10:51:10.709][17][trace][http2] [source/common/http/http2/codec_impl.cc:853] [C3] sent frame type=1 [2021-02-28 10:51:10.709][17][trace][connection] [source/common/network/connection_impl.cc:657] [C3] write ready [2021-02-28 10:51:10.709][17][trace][connection] [source/common/network/raw_buffer_socket.cc:68] [C3] write returns: 358 [2021-02-28 10:51:10.709][17][trace][connection] [source/common/network/connection_impl.cc:548] [C3] socket event: 2 [2021-02-28 10:51:10.709][17][trace][connection] [source/common/network/connection_impl.cc:657] [C3] write ready [2021-02-28 10:51:10.714][17][trace][connection] [source/common/network/connection_impl.cc:548] [C3] socket event: 3 [2021-02-28 10:51:10.714][17][trace][connection] [source/common/network/connection_impl.cc:657] [C3] write ready [2021-02-28 10:51:10.714][17][trace][connection] [source/common/network/connection_impl.cc:586] [C3] read ready. dispatch_buffered_data=false [2021-02-28 10:51:10.714][17][trace][connection] [source/common/network/raw_buffer_socket.cc:25] [C3] read returns: 135 [2021-02-28 10:51:10.714][17][trace][connection] [source/common/network/raw_buffer_socket.cc:39] [C3] read error: Resource temporarily unavailable [2021-02-28 10:51:10.714][17][trace][http2] [source/common/http/http2/codec_impl.cc:644] [C3] dispatching 135 bytes [2021-02-28 10:51:10.714][17][debug][http2] [source/common/http/http2/codec_impl.cc:890] [C3] invalid http2: Remote peer returned unexpected data while we expected SETTINGS frame. Perhaps, peer does not support HTTP/2 properly. [2021-02-28 10:51:10.714][17][trace][http2] [source/common/http/http2/codec_impl.cc:671] [C3] dispatched 135 bytes [2021-02-28 10:51:10.714][17][trace][http2] [source/common/http/http2/codec_impl.cc:924] [C3] about to send frame type=7, flags=0 [2021-02-28 10:51:10.714][17][trace][http2] [source/common/http/http2/codec_impl.cc:946] [C3] send data: bytes=34 [2021-02-28 10:51:10.714][17][trace][connection] [source/common/network/connection_impl.cc:465] [C3] writing 34 bytes, end_stream false [2021-02-28 10:51:10.715][17][trace][http2] [source/common/http/http2/codec_impl.cc:853] [C3] sent frame type=7 [2021-02-28 10:51:10.715][17][debug][http2] [source/common/http/http2/codec_impl.cc:856] [C3] sent goaway code=1 [2021-02-28 10:51:10.715][17][debug][client] [source/common/http/codec_client.cc:137] [C3] Error dispatching received data: The user callback function failed [2021-02-28 10:51:10.715][17][debug][connection] [source/common/network/connection_impl.cc:132] [C3] closing data_to_write=34 type=1 [2021-02-28 10:51:10.715][17][trace][connection] [source/common/network/raw_buffer_socket.cc:68] [C3] write returns: 34 [2021-02-28 10:51:10.715][17][debug][connection] [source/common/network/connection_impl.cc:241] [C3] closing socket: 1 [2021-02-28 10:51:10.715][17][trace][connection] [source/common/network/connection_impl.cc:407] [C3] raising connection event 1 [2021-02-28 10:51:10.716][17][debug][client] [source/common/http/codec_client.cc:99] [C3] disconnect. resetting 1 pending requests [2021-02-28 10:51:10.716][17][debug][client] [source/common/http/codec_client.cc:125] [C3] request reset [2021-02-28 10:51:10.716][17][trace][main] [source/common/event/dispatcher_impl.cc:213] item added to deferred deletion list (size=1) [2021-02-28 10:51:10.716][17][debug][pool] [source/common/conn_pool/conn_pool_base.cc:159] [C3] destroying stream: 0 remaining [2021-02-28 10:51:10.716][17][debug][router] [source/common/router/router.cc:1026] [C2][S9636672460028773107] upstream reset: reset reason: connection termination, transport failure reason: [2021-02-28 10:51:10.716][17][debug][http] [source/common/http/filter_manager.cc:839] [C2][S9636672460028773107] Sending local reply with details upstream_reset_before_response_started{connection termination} [2021-02-28 10:51:10.716][17][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x1e07bf442400 for 10000ms, min is 10000ms [2021-02-28 10:51:10.716][17][debug][http] [source/common/http/conn_manager_impl.cc:1484] [C2][S9636672460028773107] encoding headers via codec (end_stream=false): ':status', '503' 'content-length', '95' 'content-type', 'text/plain' 'date', 'Sun, 28 Feb 2021 10:51:10 GMT' 'server', 'envoy' [2021-02-28 10:51:10.716][17][trace][connection] [source/common/network/connection_impl.cc:465] [C2] writing 134 bytes, end_stream false [2021-02-28 10:51:10.716][17][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x1e07bf442400 for 10000ms, min is 10000ms [2021-02-28 10:51:10.716][17][trace][http] [source/common/http/conn_manager_impl.cc:1493] [C2][S9636672460028773107] encoding data via codec (size=95 end_stream=true) [2021-02-28 10:51:10.716][17][trace][connection] [source/common/network/connection_impl.cc:465] [C2] writing 95 bytes, end_stream false [2021-02-28 10:51:10.716][17][trace][connection] [source/common/network/connection_impl.cc:346] [C2] readDisable: disable=false disable_count=1 state=0 buffer_length=0 [2021-02-28 10:51:10.716][17][trace][main] [source/common/event/dispatcher_impl.cc:213] item added to deferred deletion list (size=2) [2021-02-28 10:51:10.716][17][trace][misc] [source/common/event/scaled_range_timer_manager_impl.cc:60] enableTimer called on 0x1e07bf442380 for 3600000ms, min is 3600000ms [2021-02-28 10:51:10.716][17][debug][pool] [source/common/conn_pool/conn_pool_base.cc:343] [C3] client disconnected, failure reason: [2021-02-28 10:51:10.716][17][trace][main] [source/common/event/dispatcher_impl.cc:213] item added to deferred deletion list (size=3) [2021-02-28 10:51:10.716][17][trace][main] [source/common/event/dispatcher_impl.cc:89] clearing deferred deletion list (size=3) [2021-02-28 10:51:10.716][17][trace][connection] [source/common/network/connection_impl.cc:548] [C2] socket event: 2 [2021-02-28 10:51:10.716][17][trace][connection] [source/common/network/connection_impl.cc:657] [C2] write ready [2021-02-28 10:51:10.716][17][trace][connection] [source/common/network/raw_buffer_socket.cc:68] [C2] write returns: 229 [2021-02-28 10:51:10.747][17][trace][connection] [source/common/network/connection_impl.cc:548] [C2] socket event: 3 [2021-02-28 10:51:10.747][17][trace][connection] [source/common/network/connection_impl.cc:657] [C2] write ready [2021-02-28 10:51:10.747][17][trace][connection] [source/common/network/connection_impl.cc:586] [C2] read ready. dispatch_buffered_data=false [2021-02-28 10:51:10.747][17][trace][connection] [source/common/network/raw_buffer_socket.cc:25] [C2] read returns: 323 [2021-02-28 10:51:10.747][17][trace][connection] [source/common/network/raw_buffer_socket.cc:39] [C2] read error: Resource temporarily unavailable
Full trace log from the above session ... here.
Apologies and thanks in advance for any pointing or suggestions. I can provide any missing reference docs as needed.
Thanks Again!
I'm going to give it a few more days, but I think I discovered the issues ... which appear to be fat-fingers, copy & paste.
- name: tags_service connect_timeout: 30s type: strict_dns lb_policy: round_robin # http2_protocol_options: {} !remove these lines load_assignment: cluster_name: tags_service endpoints: - lb_endpoints: - endpoint: address: socket_address: address: localapp-tags port_value: 80
route: cluster: tags_service auto_host_rewrite: true prefix_rewrite: "/" # add this line so that we remove the /{route}/ from the gw idle_timeout: 10s
Now I will go back and re-enable some of the settings I had previously and maybe attempt the Edge Proxy Settings. At least it is running properly now and I learned a lot.
The best part is the role that SO plays in the process. (This is not sarcasm!) After jumping around for days with different working examples, I of course copied something into my configs that were not correct (guess I need to RTFM more). Posting a SO question makes one re-evaluate all the steps and processes taken and lights a bit of a fire.
Thanks SO!