gRPC JWT Authentication not enforced

Hello,

I’m new to istio and gRPC, and running into an issue where my authentication policy requiring origin authentication over JWT is not being enforced. Below are my istio configuration files and the envoy configuration files I pulled:

apiVersion: apps/v1
kind: Deployment
metadata:
  labels:
    run: echo-server
  name: echo-server
spec:
  replicas: 1
  selector:
    matchLabels:
      run: echo-server
  template:
    metadata:
      labels:
        run: echo-server
    spec:
      containers:
      - name: echo-server
        image: saturnism/echo-server
---
apiVersion: v1
kind: Service
metadata:
  labels:
    run: echo-server
  name: echo-server
  annotations:
    service.beta.kubernetes.io/aws-load-balancer-internal: 0.0.0.0/0
    service.beta.kubernetes.io/aws-load-balancer-type: "elb"
spec:
  type: LoadBalancer
  ports:
  - name: grpc
    port: 8080
    targetPort: 8080
  selector:
    run: echo-server
  sessionAffinity: None
---
apiVersion: "authentication.istio.io/v1alpha1"
kind: "Policy"
metadata:
  name: "jwt-example"
spec:
  targets:
  - name: echo-server
  origins:
  - jwt:
      issuer: "testing@secure.istio.io"
      jwksUri: "https://raw.githubusercontent.com/istio/istio/release-1.2/security/tools/jwt/samples/jwks.json"
  principalBinding: USE_ORIGIN

Also I’m not getting any logs when the authentication is not being enforced. The above works when I’m deploy a HTTP based service. I’d appreciate any help.

I found the issue, I was not listing containerPort on the Deployment. I found this document outlining what is needed to force the traffic into the envoy proxy: https://istio.io/docs/setup/kubernetes/additional-setup/requirements/

I’m still not seeing logs from the envoy sidecar, if anyone has any hints there I’d appreciate it.

@Quanjie_Lin @YangminZhu could you take a look?

I’m getting the logs now, I do have one last question. I keep seeing a 200 returned even when the origin authentication fails:

[2019-07-02T17:08:55.207Z] "POST /com.example.grpc.EchoService/echo HTTP/2" 200 - "-" "-" 0 0 0 - "-" "grpc-java-netty/1.20.0" "334f1ee6-ded8-9c1d-82d2-7a197be285f2" "echo-server.myorg.com:8081" "-" - - 10.110.118.162:8080 10.110.112.168:51396

Why is this?

did you see both 200 and 401 in logs at the same time ?

Could you attach the full log?

@YangminZhu @Quanjie_Lin Thank you for the replies, I appreciate it. Below is the log from one call:

1	[2019-07-02 17:23:21.670][28][debug][http2] [external/envoy/source/common/http/http2/codec_impl.cc:747] [C1019] updating connection-level initial window size to 268435456
2	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/mixer/filter.cc:47] Called Mixer::Filter : Filter
3	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/mixer/filter.cc:154] Called Mixer::Filter : setDecoderFilterCallbacks
4	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/jwt_auth/jwt_authenticator.cc:82] Jwt authentication starts
5	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/jwt_auth/jwt_authenticator.cc:243] Jwt authentication completed with: OK
6	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/jwt_auth/jwt_authenticator.cc:246] The value of allow_missing_or_failed in AuthFilterConfig is: true
7	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/jwt_auth/http_filter.cc:61] JwtVerificationFilter::onDone with status OK
8	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/authn/http_filter.cc:54] AuthenticationFilter::decodeHeaders with config
9	policy {
10	  origins {
11	    jwt {
12	      issuer: "testing@secure.istio.io"
13	      jwks_uri: "https://raw.githubusercontent.com/istio/istio/release-1.2/security/tools/jwt/samples/jwks.json"
14	    }
15	  }
16	  principal_binding: USE_ORIGIN
17	}
18	jwt_output_payload_locations {
19	  key: "testing@secure.istio.io"
20	  value: "istio-sec-5406b7840708063f65cbdf52153ca364a476d68b"
21	}
22	
23	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/authn/peer_authenticator.cc:36] No method defined. Skip source authentication.
24	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/authn/origin_authenticator.cc:52] Got request path /com.example.grpc.EchoService/echo
25	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/authn/origin_authenticator.cc:66] Validating request path /com.example.grpc.EchoService/echo for jwt issuer: "testing@secure.istio.io"
26	jwks_uri: "https://raw.githubusercontent.com/istio/istio/release-1.2/security/tools/jwt/samples/jwks.json"
27	
28	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/authn/filter_context.cc:81] No dynamic_metadata found for filter jwt-auth
29	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/authn/origin_authenticator.cc:85] Origin authenticator failed
30	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/mixer/filter.cc:141] Called Mixer::Filter : encodeHeaders 0
31	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/authn/http_filter.cc:48] Called AuthenticationFilter : onDestroy
32	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/mixer/filter.cc:214] Called Mixer::Filter : onDestroy state: 0
33	[2019-07-02 17:23:21.720][28][debug][http2] [external/envoy/source/common/http/http2/codec_impl.cc:567] [C1019] stream closed: 0
34	[2019-07-02 17:23:21.720][28][debug][filter] [src/envoy/http/mixer/filter.cc:228] Called Mixer::Filter : log
35	[2019-07-02 17:23:21.721][28][debug][filter] [./src/envoy/http/mixer/report_data.h:144] No dynamic_metadata found for filter envoy.filters.http.rbac
36	[2019-07-02 17:23:21.721][28][debug][filter] [src/istio/control/client_context_base.cc:140] Report attributes: attributes {
37	  key: "connection.mtls"
38	  value {
39	    bool_value: false
40	  }
41	}
42	attributes {
43	  key: "context.protocol"
44	  value {
45	    string_value: "grpc"
46	  }
47	}
48	attributes {
49	  key: "context.prox
50	[2019-07-02 17:23:22.717][28][debug][filter] [./src/envoy/utils/header_update.h:46] Mixer forward attributes set: Cj0KCnNvdXJjZS51aWQSLxIta3ViZXJuZXRlczovL2VjaG8tc2VydmVyLTg0ODU1YmNkYzYta2o2aGIuZm9v
51	[2019-07-02 17:23:22.717][28][debug][grpc] [src/envoy/utils/grpc_transport.cc:46] Sending Report request: attributes {
52	  strings {
53	    key: 17
54	    value: -3
55	  }
56	  strings {
57	    key: 18
58	    value: -7
59	  }
60	  strings {
61	    key: 19
62	    value: 91
63	  }
64	  strings {
65	    key: 22
66	    value: -8
67	  }
68	  strings {
69	    key: 25
70	    value: -5
71	  }
72	  strings {
73	    key: 131
74	    value: -12
75	  }
76	  strings {
77	    key: 154
78	    value: -15
79	  }
80	  strings {
81	    key: 155
82	    value: -14
83	  }
84	  strings {
85	    key: 190
86	    value: -1
87	  }
88	  strings {
89	    key: 191
90	    value: -13
91	  }
92	  strings {
93	    key: 192
94	    value: -14
95	  }
96	  strings {
97	    key: 193
98	    value: -18
99	  }
100	  strings {
101	    key: 197
102	    value: -15
103	  }
104	  strings {
105	    key: 198
106	    value: -17
107	  }
108	  strings {
109	    key: 199
110	    value: -16
111	  }
112	  strings {
113	    key: 201
114	    value: 219
115	  }
116	  strings {
117	    key: 203
118	    value: -3
119	  }
120	  strings {
121	    key: 205
122	    value: -2
123	  }
124	  int64s {
125	    key: 23
126	    value: 0
127	  }
128	  int64s {
129	    key: 27
130	    value: 0
131	  }
132	  int64s {
133	    key: 30
134	    value: 200
135	  }
136	  int64s {
137	    key: 151
138	    value: 8080
139	  }
140	  int64s {
141	    key: 169
142	    value: 0
143	  }
144	  int64s {
145	    key: 170
146	    value: 209
147	  }
148	  bools {
149	    key: 177
150	    value: false
151	  }
152	  timestamps {
153	    key: 24
154	    value {
155	      seconds: 1562088201
156	      nanos: 721000163
157	    }
158	  }
159	  timestamps {
160	    key: 28
161	    value {
162	      seconds: 1562088201
163	      nanos: 721020328
164	    }
165	  }
166	  durations {
167	    key: 29
168	    value {
169	      nanos: 292429
170	    }
171	  }
172	  bytes {
173	    key: -25
174	    value: "\nnuD"
175	  }
176	  bytes {
177	    key: 150
178	    value: "\000\000\000\000\000\000\000\000\000\000\377\377\nnv\242"
179	  }
180	  string_maps {
181	    key: 15
182	    value {
183	      entries {
184	        key: -10
185	        value: -9
186	      }
187	      entries {
188	        key: -6
189	        value: 106
190	      }
191	      entries {
192	        key: 31
193	        value: -7
194	      }
195	      entries {
196	        key: 32
197	        value: 91
198	      }
199	      entries {
200	        key: 33
201	        value: -3
202	      }
203	      entries {
204	        key: 34
205	        value: -8
206	      }
207	      entries {
208	        key: 58
209	        value: -4
210	      }
211	      entries {
212	        key: 86
213	        value: -5
214	      }
215	      entries {
216	        key: 100
217	        value: 92
218	      }
219	      entries {
220	        key: 102
221	        value: -11
222	      }
223	    }
224	  }
225	  string_maps {
226	    key: 26
227	    value {
228	      entries {
229	        key: -24
230	        value: -16
231	      }
232	      entries {
233	        key: -23
234	        value: -22
235	      }
236	      entries {
237	        key: -19
238	        value: -17
239	      }
240	      entries {
241	        key: 35
242	        value: 136
243	      }
244	      entries {
245	        key: 58
246	        value: -4
247	      }
248	      entries {
249	        key: 60
250	        value: -20
251	      }
252	      entries {
253	        key: 82
254	        value: -21
255	      }
256	    }
257	  }
258	}
259	default_words: "istio://foo/services/echo-server"
260	default_words: "-"
261	default_words: "/com.example.grpc.EchoService/echo"
262	default_words: "application/grpc"
263	default_words: "grpc-java-netty/1.20.0"
264	default_words: "grpc-accept-encoding"
265	default_words: "echo-server.myorg.com:8081"
266	default_words: "https"
267	default_words: "trailers"
268	default_words: "te"
269	default_words: "be4404b1-c1c8-9a2d-8dee-b89879be85df"
270	default_words: "grpc"
271	default_words: "echo-server"
272	default_words: "foo"
273	default_words: "kubernetes://echo-server-84855bcdc6-kj6hb.foo"
274	default_words: "Origin authentication failed."
275	default_words: "16"
276	default_words: "echo-server.foo.svc.cluster.local"
277	default_words: "grpc-status"
278	default_words: "Tue, 02 Jul 2019 17:23:21 GMT"
279	default_words: "istio-envoy"
280	default_words: "echo-server.foo.svc.cluster.local:8081/*"
281	default_words: "x-envoy-decorator-operation"
282	default_words: "grpc-message"
283	default_words: "origin.ip"
284	global_word_count: 221
285	repeated_attributes_semantics: INDEPENDENT_ENCODING
286	
287	[2019-07-02 17:23:22.719][28][debug][grpc] [src/envoy/utils/grpc_transport.cc:67] Report response:
288	[2019-07-02 17:23:22.719][28][debug][http2] [external/envoy/source/common/http/http2/codec_impl.cc:567] [C28] stream closed: 0
289	[2019-07-02 17:23:25.686][26][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
290	[2019-07-02 17:23:26.113][28][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
291	[2019-07-02T17:23:21.720Z] "POST /com.example.grpc.EchoService/echo HTTP/2" 200 - "-" "-" 0 0 0 - "-" "grpc-java-netty/1.20.0" "be4404b1-c1c8-9a2d-8dee-b89879be85df" "echo-server.myorg.com:8081" "-" - - 10.110.118.162:8080 10.110.117.68:39744 -
292	[2019-07-02 17:23:35.687][28][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
293	[2019-07-02 17:23:36.113][26][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
294	[2019-07-02 17:23:45.687][28][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
295	[2019-07-02 17:23:46.113][26][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
296	[2019-07-02 17:23:55.686][28][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
297	[2019-07-02 17:23:56.114][26][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted
298	[2019-07-02 17:24:05.687][28][debug][filter] [external/envoy/source/extensions/filters/listener/original_dst/original_dst.cc:18] original_dst: New connection accepted

I think this looks like gRPC JWT Authentication silently failing in Istio [workaround], which has been resolved. Could you take a look @jammerful?

@philliple I ran into a different issue that caused the traffic to bypass the envoy proxy. At this point I was just curious why I’m getting a 200 return at the end of the logs even though origin authN fails and the client is getting origin authN failure.