Android client stopped to authenticate "subject_token is invalid"

Tunneler Apps Ziti Mobile Edge for Android
1

Yesterday, while I was using it on my phone, I lost the connection to my network.

Now my android Client is unable to authenticate.

The controller is up and the other tunnelers work just fine.

on the controller I can see

Oct 31 11:32:57 homeoverlay ziti[951]: 2025/10/31 11:32:57 WARN request error oidc_error.description="subject_token is invalid" oidc_error.type=invalid_request

I tried to reenroll the identity. From ZAC the identity seems enrolled, but no difference on my phone.

I just sent a debug email to developpers from my phone.

2

we are looking into OIDC auth issues. for now can you try turning of OIDC auth support in the controller? comment out edge-oidc binding block

3

Are you by chance using the identity configuration settings under web in your controller?

Example (See the “this section” comment in the YAML)

web:
  - name: all-apis-localhost
    bindPoints:
      - interface: 127.0.0.1:1280
        address: 127.0.0.1:1280

        # this section
        identity:
          cert:                 /some/path/to/some/cert.pem
          server_cert:          /some/path/to/some/cert.pem
          key:                  /some/path/to/some/key.pem
          ca:                   /some/path/to/some/cas.pem
    apis:
      - binding: health-checks
      - binding: fabric
      - binding: edge-management
      - binding: edge-client
      - binding: edge-oidc
4

my conf is

web:

name: client
bindPoints:

interface: 0.0.0.0:443
address: ziti.my.domain:443
identity:
ca:          "edge-controller-root-ca.cert"
key:         "server.key"
server_cert: "server.chain.pem"
cert:        "client.chain.pem"

options:
idleTimeout: 5000ms  #http timeouts, new
readTimeout: 5000ms
writeTimeout: 100000ms
minTLSVersion: TLS1.2
maxTLSVersion: TLS1.3
apis:

binding: edge-client
options: { }

binding: edge-oidc
options: { }

Management is in another section with zac

I tried to comment edge-oidc binding with no success: android is still stuck on initial

5

Do you mind sharing the root identity section? It is normally the first stanza in the config file.

6

Openziti has been configured with the quickstart on February and has been working fine since then.

Yesterday I was using some service with my phone while a was on a train. I lost data connection in a tunnel and I was not able to connect any more. I switched to VPN connection without looking at the app. Since today, when I found I was unauthanticated.

Every other client is still working fine.

I cleared android storage and enrolled a new identity without success.

ziti binay is ziti-1.6.7

my conf is

v: 3

db:                     "/home/ziti/.ziti/quickstart/homeoverlay/db/ctrl.db"

identity:
  cert:        "/home/ziti/.ziti/quickstart/homeoverlay/pki/ziti.my.domain-intermediate/certs/ziti.my.domain-client.chain.pem"
  server_cert: "/home/ziti/.ziti/quickstart/homeoverlay/pki/ziti.my.domain-intermediate/certs/ziti.my.domain-server.chain.pem"
  key:         "/home/ziti/.ziti/quickstart/homeoverlay/pki/ziti.my.domain-intermediate/keys/ziti.my.domain-server.key"
  ca:          "/home/ziti/.ziti/quickstart/homeoverlay/pki/cas.pem"

ctrl:
  options:
    advertiseAddress: tls:ziti.my.domain:8440
  listener:             tls:0.0.0.0:8440

healthChecks:
  boltCheck:
    interval: 30s
    timeout: 20s
    initialDelay: 30s

edge:
  api:
    sessionTimeout: 30m
    address: ziti.my.domain:443
  enrollment:
    signingCert:
      cert: /home/ziti/.ziti/quickstart/homeoverlay/pki/signing.pem
      key:  /home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-signing-intermediate/keys/homeoverlay-signing-intermediate.key
    edgeIdentity:
      duration: 180m
    edgeRouter:
      duration: 180m

web:
  - name: client
    bindPoints:
      - interface: 0.0.0.0:443
        address: ziti.my.domain:443
    identity:
      ca:          "/home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-edge-controller-root-ca/certs/homeoverlay-edge-controller-root-ca.cert"
      key:         "/home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-edge-controller-intermediate/keys/ziti.my.domain-server.key"
      server_cert: "/home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-edge-controller-intermediate/certs/ziti.my.domain-server.chain.pem"
      cert:        "/home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-edge-controller-intermediate/certs/ziti.my.domain-client.chain.pem"

    options:
      idleTimeout: 5000ms  #http timeouts, new
      readTimeout: 5000ms
      writeTimeout: 100000ms
      minTLSVersion: TLS1.2
      maxTLSVersion: TLS1.3
    apis:
      - binding: edge-client
        options: { }
      - binding: edge-oidc
        options: { }
  - name: management
    bindPoints:
      - interface: 0.0.0.0:18441
        address: 127.0.0.1:18441
    identity:
      ca:          "/home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-edge-controller-root-ca/certs/homeoverlay-edge-controller-root-ca.cert"
      key:         "/home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-edge-controller-intermediate/keys/ziti.my.domain-server.key"
      server_cert: "/home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-edge-controller-intermediate/certs/ziti.my.domain-server.chain.pem"
      cert:        "/home/ziti/.ziti/quickstart/homeoverlay/pki/homeoverlay-edge-controller-intermediate/certs/ziti.my.domain-client.chain.pem"

    options:
      idleTimeout: 5000ms  #http timeouts, new
      readTimeout: 5000ms
      writeTimeout: 100000ms
      minTLSVersion: TLS1.2
      maxTLSVersion: TLS1.3

    apis:
      - binding: edge-management
        options: { }
      - binding: fabric
        options: { }
      - binding: edge-oidc
        options: { }
      - binding: zac
        options:
          location: ./console
          indexFile: index.html
7

client log

10-31 22:21:10.434 31012  5089 E ziti-sdk:ziti.c:1560 update_identity_data(): ztx[2] failed to get identity_data: The request could not be completed. The session is not authorized or the credentials are invalid[UNAUTHORIZED]
10-31 22:21:10.434 31012  5089 W ziti-sdk:ziti.c:1562 update_identity_data(): ztx[2] api session is no longer valid. Trying to re-auth
10-31 22:21:10.434 31012  5089 W ziti-sdk:ziti.c:223 ziti_set_unauthenticated(): ztx[2] auth error: The request could not be completed. The session is not authorized or the credentials are invalid
10-31 22:21:10.434 31012  5089 D ziti-sdk:ziti.c:226 ziti_set_unauthenticated(): ztx[2] setting auth_state[0] to 0
10-31 22:21:10.434 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:21:10.434 31012  5089 W tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event(): ziti_ctx controller connections failed: failed to authenticate
10-31 22:21:10.435 31012  5089 I Tunnel  : event: {"identifier":"mBlld39v8e","type":"ContextEvent","status":"failed to authenticate","code":-14}
10-31 22:21:10.435 31012  5089 D ziti-sdk:ziti.c:444 ziti_force_api_session_refresh(): ztx[2] forcing session refresh
10-31 22:21:10.435 31012  5089 D ziti-sdk:oidc.c:967 refresh_time_cb(): oidc[internal] refreshing OIDC token
10-31 22:21:10.436 31012 31012 D model   : received event[ContextEvent(identifier=mBlld39v8e, status=failed to authenticate, name=null, controller=null)]
10-31 22:21:10.446 31012  5089 D ziti-sdk:ziti_ctrl.c:500 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] completed paging request GET[/current-identity/edge-routers] in 0.145 s
10-31 22:21:10.446 31012  5089 E ziti-sdk:ziti_ctrl.c:527 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] API request[/current-identity/edge-routers?limit=25&offset=0] failed code[UNAUTHORIZED] message[The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:21:10.447 31012  5089 E ziti-sdk:ziti.c:1484 edge_routers_cb(): ztx[2] failed to get current edge routers: code[401] UNAUTHORIZED/The request could not be completed. The session is not authorized or the credentials are invalid
10-31 22:21:10.500 31012  5089 D ziti-sdk:ziti_ctrl.c:505 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] completed GET[/current-api-session/service-updates] in 0.198 s
10-31 22:21:10.500 31012  5089 E ziti-sdk:ziti_ctrl.c:527 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] API request[/current-api-session/service-updates] failed code[UNAUTHORIZED] message[The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:21:10.501 31012  5089 W ziti-sdk:ziti.c:1432 check_service_update(): ztx[2] failed to poll service updates: code[401] err[-14/The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:21:10.520 31012  5089 D ziti-sdk:oidc.c:936 refresh_cb(): oidc[internal] token refresh success
10-31 22:21:10.520 31012  5089 E ziti-sdk:oidc.c:914 oidc_client_set_tokens(): oidc[internal] access_token was not provided by IdP
10-31 22:21:10.520 31012  5089 W ziti-sdk:ziti.c:223 ziti_set_unauthenticated(): ztx[2] auth error: failed to auth: 4
10-31 22:21:10.520 31012  5089 D ziti-sdk:ziti.c:226 ziti_set_unauthenticated(): ztx[2] setting auth_state[0] to 0
10-31 22:21:10.521 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:21:10.521 31012  5089 W tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event(): ziti_ctx controller connections failed: unexpected error
10-31 22:21:10.521 31012  5089 I Tunnel  : event: {"identifier":"mBlld39v8e","type":"ContextEvent","status":"unexpected error","code":4}
10-31 22:21:10.523 31012 31012 D model   : received event[ContextEvent(identifier=mBlld39v8e, status=unexpected error, name=null, controller=null)]
10-31 22:21:10.539 31012  5089 D ziti-sdk:oidc.c:936 refresh_cb(): oidc[internal] token refresh success
10-31 22:21:10.539 31012  5089 E ziti-sdk:oidc.c:914 oidc_client_set_tokens(): oidc[internal] access_token was not provided by IdP
10-31 22:21:10.539 31012  5089 W ziti-sdk:ziti.c:223 ziti_set_unauthenticated(): ztx[2] auth error: failed to auth: 4
10-31 22:21:10.539 31012  5089 D ziti-sdk:ziti.c:226 ziti_set_unauthenticated(): ztx[2] setting auth_state[0] to 0
10-31 22:21:10.539 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:21:10.539 31012  5089 W tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event(): ziti_ctx controller connections failed: unexpected error
10-31 22:21:10.540 31012  5089 I Tunnel  : event: {"identifier":"mBlld39v8e","type":"ContextEvent","status":"unexpected error","code":4}
10-31 22:21:10.541 31012 31012 D model   : received event[ContextEvent(identifier=mBlld39v8e, status=unexpected error, name=null, controller=null)]
10-31 22:21:30.313 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:21:50.351 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:26:02.004 31012 31012 I ZitiVPNService: onCreate()
10-31 22:26:02.008 31012  5108 I ZitiVPNService: network available: 110, caps:[ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED LinkUpBandwidth>=321960Kbps LinkDnBandwidth>=338906Kbps SignalStrength: -59 AdministratorUids: [] RequestorUid: -1 RequestorPackageName: null]
10-31 22:26:02.008 31012  5108 I ZitiVPNService: active[110]
10-31 22:26:02.008 31012  5108 I ZitiVPNService: link change[110], active[110]
10-31 22:26:02.008 31012  5108 I ZitiVPNService: link[110] addresses: [/192.168.4.11, /xxxx:xxxx:xxxx:xxxx:e0e6:77b5:e864:8300, /xxxx:xxxx:xxxx:xxxx:e8f2:76f6:e994:2c62]
10-31 22:26:02.009 31012  5108 I ZitiVPNService: link[110] nameservers: [/192.168.4.250]
10-31 22:26:02.009 31012  5108 I ZitiVPNService: set upstream DNS[[192.168.4.250]]
10-31 22:26:02.009 31012  5108 D Tunnel  : cmd[122] = SetUpstreamDNS:[{"host":"192.168.4.250"}]
10-31 22:26:02.009 31012  5089 I tunnel-cbs:ziti_dns.c:273 ziti_dns_set_upstream(): DNS upstream[1] is set to 192.168.4.250:53
10-31 22:26:02.009 31012  5089 I Tunnel  : resp = {"Success":true,"Code":0}
10-31 22:26:02.009 31012  5089 D Tunnel  : result[122] = SetUpstreamDNS:TunnelResult(success=true, code=0, error=null, data=null)
10-31 22:26:02.011 31012 13498 I ZitiVPNService: command monitor started
10-31 22:26:02.011 31012 13498 I ZitiVPNService: received cmd[stop]
10-31 22:26:02.011 31012 13498 I ZitiVPNService: tunnel stop success
10-31 22:26:02.011 31012 13498 I ZitiVPNService: monitoring route updates
10-31 22:26:06.470 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:26:11.592 31012 31012 I ZitiVPNService: onDestroy
10-31 22:26:11.594 31012 13498 I ZitiVPNService: stopped route updates
10-31 22:26:16.679 31012  5078 W openziti.mobil: Reducing the number of considered missed Gc histogram windows from 120 to 100
10-31 22:26:16.682 31012  5080 W System  : A resource failed to call dispose. 
10-31 22:26:26.414 31012  5089 W ziti-sdk:ziti_ctrl.c:817 verify_api_session(): ctrl[https://ziti.my.domain:443] no API session
10-31 22:26:26.415 31012  5089 E ziti-sdk:ziti.c:1560 update_identity_data(): ztx[2] failed to get identity_data: no api session token set for ziti_controller[UNAUTHORIZED]
10-31 22:26:26.415 31012  5089 W ziti-sdk:ziti.c:1562 update_identity_data(): ztx[2] api session is no longer valid. Trying to re-auth
10-31 22:26:26.415 31012  5089 W ziti-sdk:ziti.c:223 ziti_set_unauthenticated(): ztx[2] auth error: no api session token set for ziti_controller
10-31 22:26:26.415 31012  5089 D ziti-sdk:ziti.c:226 ziti_set_unauthenticated(): ztx[2] setting auth_state[0] to 0
10-31 22:26:26.415 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:26:26.416 31012  5089 W tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event(): ziti_ctx controller connections failed: failed to authenticate
10-31 22:26:26.416 31012  5089 I Tunnel  : event: {"identifier":"mBlld39v8e","type":"ContextEvent","status":"failed to authenticate","code":-14}
10-31 22:26:26.417 31012  5089 D ziti-sdk:ziti.c:444 ziti_force_api_session_refresh(): ztx[2] forcing session refresh
10-31 22:26:26.417 31012  5089 W ziti-sdk:ziti_ctrl.c:817 verify_api_session(): ctrl[https://ziti.my.domain:443] no API session
10-31 22:26:26.418 31012  5089 E ziti-sdk:ziti.c:1484 edge_routers_cb(): ztx[2] failed to get current edge routers: code[0] UNAUTHORIZED/no api session token set for ziti_controller
10-31 22:26:26.418 31012  5089 W ziti-sdk:ziti_ctrl.c:817 verify_api_session(): ctrl[https://ziti.my.domain:443] no API session
10-31 22:26:26.418 31012  5089 W ziti-sdk:ziti.c:1432 check_service_update(): ztx[2] failed to poll service updates: code[0] err[-14/no api session token set for ziti_controller]
10-31 22:26:26.418 31012  5089 D ziti-sdk:oidc.c:967 refresh_time_cb(): oidc[internal] refreshing OIDC token
10-31 22:26:26.418 31012  5089 D ziti-sdk:oidc.c:971 refresh_time_cb(): oidc[internal] must restart authentication flow: no refresh_token
10-31 22:26:26.418 31012  5089 D ziti-sdk:oidc_auth.c:161 token_cb(): restarting internal OIDC flow
10-31 22:26:26.419 31012  5089 D ziti-sdk:oidc.c:731 oidc_client_start(): oidc[internal] requesting authentication code from auth_url[https://ziti.my.domain:443/oidc/authorize]
10-31 22:26:26.478 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:26:26.575 31012  5089 D ziti-sdk:oidc.c:413 auth_cb(): oidc[internal] 302 Found err[(null)] body=null
10-31 22:26:26.576 31012  5089 D ziti-sdk:oidc.c:427 auth_cb(): oidc[internal] login with path[/oidc/login/cert?id=82f366da-123e-4d40-8dd4-ccbb64c0043e] 
10-31 22:26:26.638 31012  5089 D ziti-sdk:oidc.c:358 login_cb(): oidc[internal] 302 login[(null)] body = null
10-31 22:26:26.649 31012  5089 I ziti-sdk:oidc.c:325 request_token(): requesting token path[https://ziti.my.domain:443/oidc/oauth/token] auth[DNCUrLBSvZ6rmA1HZPweDFfGPXUJe2JDz66NiXJgC8Ap5NZoMGF6p8gLKT3mv3Ywx4SUiA&state=I0SdUY4X26_9LG_hVvhjo-Z3XX0aKpOiUyjHk_n7]
10-31 22:26:26.733 31012  5089 D ziti-sdk:oidc.c:309 token_cb(): oidc[internal] 200 OK err[(null)]
10-31 22:26:26.733 31012  5089 D ziti-sdk:oidc.c:911 oidc_client_set_tokens(): oidc[internal] using access_token={"aud":["openziti"],"client_id":"openziti","exp":1761947787,"iat":1761945987,"iss":"https://ziti.my.domain:443/oidc","jti":"bc8492b5-2fc8-4680-b957-a5eb9262d84c","nbf":1761945987,"scopes":["openid","offline_access"],"sub":"mBlld39v8e","z_aid":"openziti","z_asid":"f222fc1e-f8c4-4c3d-8d2c-b51ad608af28","z_authid":"kzB5aOwv5","z_cer":false,"z_cfs":["7b81a15a9f5f8334999e79af450eaf01155e9275","3141b96844426efb84b4547f053443eae1e3cec3","836ae39f97e9628d877149315b5a2a8d47b575b8"],"z_ckrr":false,"z_env":{"arch":"aarch64","domain":"localdomain","hostname":"localhost","os":"Android","osRelease":"11","osVersion":"2022-10-05"},"z_iccc":false,"z_ice":true,"z_ra":"185.242.182.33:7850","z_sdk":{"appId":"org.openziti.mobile","appVersion":"v0.18.0","branch":"HEAD","revision":"ge4d8dc7","type":"ziti-sdk-c","version":"1.9.10"},"z_t":"a"}
10-31 22:26:26.733 31012  5089 D ziti-sdk:ziti.c:384 ziti_set_fully_authenticated(): ztx[2] setting auth_state[0] to 3
10-31 22:26:26.733 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:26:26.734 31012  5089 D ziti-sdk:ziti_ctrl.c:1108 ctrl_paging_req(): ctrl[https://ziti.my.domain:443] starting paging request GET[/controllers]
10-31 22:26:26.734 31012  5089 D ziti-sdk:oidc.c:928 oidc_client_set_tokens(): oidc[internal] scheduling token refresh in 1769 seconds
10-31 22:26:26.736 31012  5089 D ziti-sdk:ziti_ctrl.c:1108 ctrl_paging_req(): ctrl[https://ziti.my.domain:443] starting paging request GET[/current-identity/edge-routers]
10-31 22:26:26.736 31012  5089 D ziti-sdk:posture.c:213 ziti_send_posture_data(): ztx[2] posture checks must_send set to TRUE, new_session_id[TRUE], must_send_every_time[TRUE], new_controller_instance[FALSE]
10-31 22:26:26.841 31012  5089 D ziti-sdk:ziti_ctrl.c:500 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] completed paging request GET[/controllers] in 0.107 s
10-31 22:26:26.841 31012  5089 E ziti-sdk:ziti_ctrl.c:527 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] API request[/controllers?limit=25&offset=0] failed code[UNAUTHORIZED] message[The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:26:26.841 31012  5089 W ziti-sdk:ziti.c:333 ctrl_list_cb(): ztx[2] failed to list HA controllers UNAUTHORIZED/The request could not be completed. The session is not authorized or the credentials are invalid
10-31 22:26:26.863 31012  5089 D ziti-sdk:ziti_ctrl.c:505 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] completed GET[/current-api-session] in 0.129 s
10-31 22:26:26.863 31012  5089 E ziti-sdk:ziti_ctrl.c:527 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] API request[/current-api-session] failed code[UNAUTHORIZED] message[The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:26:26.863 31012  5089 E ziti-sdk:ziti_ctrl.c:389 ctrl_login_cb(): ctrl[https://ziti.my.domain:443] UNAUTHORIZED(The request could not be completed. The session is not authorized or the credentials are invalid)
10-31 22:26:26.863 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:26:26.872 31012  5089 D ziti-sdk:ziti_ctrl.c:505 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] completed GET[/current-identity] in 0.138 s
10-31 22:26:26.873 31012  5089 E ziti-sdk:ziti_ctrl.c:527 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] API request[/current-identity] failed code[UNAUTHORIZED] message[The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:26:26.873 31012  5089 E ziti-sdk:ziti.c:1560 update_identity_data(): ztx[2] failed to get identity_data: The request could not be completed. The session is not authorized or the credentials are invalid[UNAUTHORIZED]
10-31 22:26:26.873 31012  5089 W ziti-sdk:ziti.c:1562 update_identity_data(): ztx[2] api session is no longer valid. Trying to re-auth
10-31 22:26:26.873 31012  5089 W ziti-sdk:ziti.c:223 ziti_set_unauthenticated(): ztx[2] auth error: The request could not be completed. The session is not authorized or the credentials are invalid
10-31 22:26:26.873 31012  5089 D ziti-sdk:ziti.c:226 ziti_set_unauthenticated(): ztx[2] setting auth_state[3] to 0
10-31 22:26:26.873 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:26:26.873 31012  5089 W tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event(): ziti_ctx controller connections failed: failed to authenticate
10-31 22:26:26.873 31012  5089 I Tunnel  : event: {"identifier":"mBlld39v8e","type":"ContextEvent","status":"failed to authenticate","code":-14}
10-31 22:26:26.873 31012  5089 D ziti-sdk:ziti.c:444 ziti_force_api_session_refresh(): ztx[2] forcing session refresh
10-31 22:26:26.873 31012  5089 D ziti-sdk:oidc.c:967 refresh_time_cb(): oidc[internal] refreshing OIDC token
10-31 22:26:26.884 31012  5089 D ziti-sdk:ziti_ctrl.c:505 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] completed GET[/current-identity] in 0.148 s
10-31 22:26:26.884 31012  5089 E ziti-sdk:ziti_ctrl.c:527 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] API request[/current-identity] failed code[UNAUTHORIZED] message[The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:26:26.884 31012  5089 E ziti-sdk:ziti.c:1560 update_identity_data(): ztx[2] failed to get identity_data: The request could not be completed. The session is not authorized or the credentials are invalid[UNAUTHORIZED]
10-31 22:26:26.884 31012  5089 W ziti-sdk:ziti.c:1562 update_identity_data(): ztx[2] api session is no longer valid. Trying to re-auth
10-31 22:26:26.884 31012  5089 W ziti-sdk:ziti.c:223 ziti_set_unauthenticated(): ztx[2] auth error: The request could not be completed. The session is not authorized or the credentials are invalid
10-31 22:26:26.884 31012  5089 D ziti-sdk:ziti.c:226 ziti_set_unauthenticated(): ztx[2] setting auth_state[0] to 0
10-31 22:26:26.884 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:26:26.884 31012  5089 W tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event(): ziti_ctx controller connections failed: failed to authenticate
10-31 22:26:26.885 31012  5089 I Tunnel  : event: {"identifier":"mBlld39v8e","type":"ContextEvent","status":"failed to authenticate","code":-14}
10-31 22:26:26.885 31012  5089 D ziti-sdk:ziti.c:444 ziti_force_api_session_refresh(): ztx[2] forcing session refresh
10-31 22:26:26.885 31012  5089 D ziti-sdk:oidc.c:967 refresh_time_cb(): oidc[internal] refreshing OIDC token
10-31 22:26:26.906 31012  5089 D ziti-sdk:ziti_ctrl.c:500 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] completed paging request GET[/current-identity/edge-routers] in 0.169 s
10-31 22:26:26.906 31012  5089 E ziti-sdk:ziti_ctrl.c:527 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] API request[/current-identity/edge-routers?limit=25&offset=0] failed code[UNAUTHORIZED] message[The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:26:26.906 31012  5089 E ziti-sdk:ziti.c:1484 edge_routers_cb(): ztx[2] failed to get current edge routers: code[401] UNAUTHORIZED/The request could not be completed. The session is not authorized or the credentials are invalid
10-31 22:26:26.945 31012  5089 D ziti-sdk:ziti_ctrl.c:505 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] completed GET[/current-api-session/service-updates] in 0.209 s
10-31 22:26:26.945 31012  5089 E ziti-sdk:ziti_ctrl.c:527 ctrl_body_cb(): ctrl[https://ziti.my.domain:443] API request[/current-api-session/service-updates] failed code[UNAUTHORIZED] message[The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:26:26.945 31012  5089 W ziti-sdk:ziti.c:1432 check_service_update(): ztx[2] failed to poll service updates: code[401] err[-14/The request could not be completed. The session is not authorized or the credentials are invalid]
10-31 22:26:26.963 31012  5089 D ziti-sdk:oidc.c:936 refresh_cb(): oidc[internal] token refresh success
10-31 22:26:26.963 31012  5089 E ziti-sdk:oidc.c:914 oidc_client_set_tokens(): oidc[internal] access_token was not provided by IdP
10-31 22:26:26.963 31012  5089 W ziti-sdk:ziti.c:223 ziti_set_unauthenticated(): ztx[2] auth error: failed to auth: 4
10-31 22:26:26.963 31012  5089 D ziti-sdk:ziti.c:226 ziti_set_unauthenticated(): ztx[2] setting auth_state[0] to 0
10-31 22:26:26.963 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:26:26.963 31012  5089 W tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event(): ziti_ctx controller connections failed: unexpected error
10-31 22:26:26.963 31012  5089 I Tunnel  : event: {"identifier":"mBlld39v8e","type":"ContextEvent","status":"unexpected error","code":4}
10-31 22:26:26.981 31012  5089 D ziti-sdk:oidc.c:936 refresh_cb(): oidc[internal] token refresh success
10-31 22:26:26.981 31012  5089 E ziti-sdk:oidc.c:914 oidc_client_set_tokens(): oidc[internal] access_token was not provided by IdP
10-31 22:26:26.981 31012  5089 W ziti-sdk:ziti.c:223 ziti_set_unauthenticated(): ztx[2] auth error: failed to auth: 4
10-31 22:26:26.981 31012  5089 D ziti-sdk:ziti.c:226 ziti_set_unauthenticated(): ztx[2] setting auth_state[0] to 0
10-31 22:26:26.981 31012  5089 D ziti-sdk:ziti_ctrl.c:380 ziti_ctrl_clear_auth(): ctrl[https://ziti.my.domain:443] clearing api session token for ziti_controller
10-31 22:26:26.982 31012  5089 W tunnel-cbs:ziti_tunnel_ctrl.c:1018 on_ziti_event(): ziti_ctx controller connections failed: unexpected error
10-31 22:26:26.982 31012  5089 I Tunnel  : event: {"identifier":"mBlld39v8e","type":"ContextEvent","status":"unexpected error","code":4}
10-31 22:26:46.775 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:27:06.796 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:27:26.813 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:27:46.816 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:28:02.282 31012 31012 I ZitiVPNService: onCreate()
10-31 22:28:02.283 31012 13655 I ZitiVPNService: command monitor started
10-31 22:28:02.283 31012 13655 I ZitiVPNService: received cmd[stop]
10-31 22:28:02.283 31012 13655 I ZitiVPNService: tunnel stop success
10-31 22:28:02.283 31012 13655 I ZitiVPNService: monitoring route updates
10-31 22:28:02.284 31012  5108 I ZitiVPNService: network available: 110, caps:[ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED LinkUpBandwidth>=321960Kbps LinkDnBandwidth>=338906Kbps SignalStrength: -59 AdministratorUids: [] RequestorUid: -1 RequestorPackageName: null]
10-31 22:28:02.284 31012  5108 I ZitiVPNService: active[110]
10-31 22:28:02.285 31012  5108 I ZitiVPNService: link change[110], active[110]
10-31 22:28:02.285 31012  5108 I ZitiVPNService: link[110] addresses: [/192.168.4.11, /xxxx:xxxx:xxxx:xxxx:e0e6:77b5:e864:8300, /xxxx:xxxx:xxxx:xxxx:e8f2:76f6:e994:2c62]
10-31 22:28:02.285 31012  5108 I ZitiVPNService: link[110] nameservers: [/192.168.4.250]
10-31 22:28:02.285 31012  5108 I ZitiVPNService: set upstream DNS[[192.168.4.250]]
10-31 22:28:02.285 31012  5108 D Tunnel  : cmd[123] = SetUpstreamDNS:[{"host":"192.168.4.250"}]
10-31 22:28:02.285 31012  5089 I tunnel-cbs:ziti_dns.c:273 ziti_dns_set_upstream(): DNS upstream[1] is set to 192.168.4.250:53
10-31 22:28:02.285 31012  5089 I Tunnel  : resp = {"Success":true,"Code":0}
10-31 22:28:02.285 31012  5089 D Tunnel  : result[123] = SetUpstreamDNS:TunnelResult(success=true, code=0, error=null, data=null)
10-31 22:28:06.821 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:28:13.133 31012 31012 D Tunnel  : cmd[124] = ZitiDump:{"Identifier":"mBlld39v8e"}
10-31 22:28:13.133 31012  5089 I tunnel-cbs:ziti_tunnel_ctrl.c:323 process_cmd(): ziti dump started 
10-31 22:28:13.133 31012  5089 I tunnel-cbs:ziti_tunnel_ctrl.c:383 process_cmd(): ziti dump finished 
10-31 22:28:13.133 31012  5089 I Tunnel  : resp = {"Success":true,"Data":{ },"Code":0}
10-31 22:28:13.134 31012  5089 D Tunnel  : result[124] = ZitiDump:TunnelResult(success=true, code=0, error=null, data={})
10-31 22:28:13.152 31012 31012 I ZitiVPNService: onDestroy
10-31 22:28:13.401 31012  6601 E DatabaseUtils: Writing exception to parcel
10-31 22:28:13.401 31012  6601 E DatabaseUtils: java.lang.SecurityException: Permission Denial: reading org.openziti.mobile.debug.FeedbackProvider uri content://org.openziti.mobile.provider/logs/logs/log.zip from pid=4241, uid=1000 requires the provider be exported, or grantUriPermission()
10-31 22:28:13.401 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider.enforceReadPermissionInner(ContentProvider.java:820)
10-31 22:28:13.401 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider$Transport.enforceReadPermission(ContentProvider.java:684)
10-31 22:28:13.401 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider$Transport.query(ContentProvider.java:239)
10-31 22:28:13.401 31012  6601 E DatabaseUtils: 	at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:106)
10-31 22:28:13.401 31012  6601 E DatabaseUtils: 	at android.os.Binder.execTransactInternal(Binder.java:1154)
10-31 22:28:13.401 31012  6601 E DatabaseUtils: 	at android.os.Binder.execTransact(Binder.java:1123)
10-31 22:28:13.422 31012  6601 E DatabaseUtils: Writing exception to parcel
10-31 22:28:13.422 31012  6601 E DatabaseUtils: java.lang.SecurityException: Permission Denial: reading org.openziti.mobile.debug.FeedbackProvider uri content://org.openziti.mobile.provider/logs/logs/log.zip from pid=4241, uid=1000 requires the provider be exported, or grantUriPermission()
10-31 22:28:13.422 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider.enforceReadPermissionInner(ContentProvider.java:820)
10-31 22:28:13.422 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider$Transport.enforceReadPermission(ContentProvider.java:684)
10-31 22:28:13.422 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider$Transport.query(ContentProvider.java:239)
10-31 22:28:13.422 31012  6601 E DatabaseUtils: 	at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:106)
10-31 22:28:13.422 31012  6601 E DatabaseUtils: 	at android.os.Binder.execTransactInternal(Binder.java:1154)
10-31 22:28:13.422 31012  6601 E DatabaseUtils: 	at android.os.Binder.execTransact(Binder.java:1123)
10-31 22:28:13.555 31012  6601 E DatabaseUtils: Writing exception to parcel
10-31 22:28:13.555 31012  6601 E DatabaseUtils: java.lang.SecurityException: Permission Denial: reading org.openziti.mobile.debug.FeedbackProvider uri content://org.openziti.mobile.provider/logs/logs/log.zip from pid=4241, uid=1000 requires the provider be exported, or grantUriPermission()
10-31 22:28:13.555 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider.enforceReadPermissionInner(ContentProvider.java:820)
10-31 22:28:13.555 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider$Transport.enforceReadPermission(ContentProvider.java:684)
10-31 22:28:13.555 31012  6601 E DatabaseUtils: 	at android.content.ContentProvider$Transport.query(ContentProvider.java:239)
10-31 22:28:13.555 31012  6601 E DatabaseUtils: 	at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:106)
10-31 22:28:13.555 31012  6601 E DatabaseUtils: 	at android.os.Binder.execTransactInternal(Binder.java:1154)
10-31 22:28:13.555 31012  6601 E DatabaseUtils: 	at android.os.Binder.execTransact(Binder.java:1123)
10-31 22:28:15.097 31012 31012 I ZitiVPNService: onCreate()
10-31 22:28:15.100 31012  5108 I ZitiVPNService: network available: 110, caps:[ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED LinkUpBandwidth>=321960Kbps LinkDnBandwidth>=338906Kbps SignalStrength: -59 AdministratorUids: [] RequestorUid: -1 RequestorPackageName: null]
10-31 22:28:15.100 31012  5108 I ZitiVPNService: active[110]
10-31 22:28:15.100 31012  5108 I ZitiVPNService: link change[110], active[110]
10-31 22:28:15.100 31012  5108 I ZitiVPNService: link[110] addresses: [/192.168.4.11, /xxxx:xxxx:xxxx:xxxx:e0e6:77b5:e864:8300, /xxxx:xxxx:xxxx:xxxx:e8f2:76f6:e994:2c62]
10-31 22:28:15.100 31012  5108 I ZitiVPNService: link[110] nameservers: [/192.168.4.250]
10-31 22:28:15.100 31012  5108 I ZitiVPNService: set upstream DNS[[192.168.4.250]]
10-31 22:28:15.100 31012  5108 D Tunnel  : cmd[125] = SetUpstreamDNS:[{"host":"192.168.4.250"}]
10-31 22:28:15.101 31012  5089 I tunnel-cbs:ziti_dns.c:273 ziti_dns_set_upstream(): DNS upstream[1] is set to 192.168.4.250:53
10-31 22:28:15.101 31012  5089 I Tunnel  : resp = {"Success":true,"Code":0}
10-31 22:28:15.101 31012 13689 I ZitiVPNService: command monitor started
10-31 22:28:15.101 31012 13689 I ZitiVPNService: received cmd[stop]
10-31 22:28:15.101 31012  5089 D Tunnel  : result[125] = SetUpstreamDNS:TunnelResult(success=true, code=0, error=null, data=null)
10-31 22:28:15.101 31012 13689 I ZitiVPNService: tunnel stop success
10-31 22:28:15.101 31012 13689 I ZitiVPNService: monitoring route updates
10-31 22:28:17.163 31012 31012 I ZitiVPNService: onDestroy
10-31 22:28:19.137 31012 31012 I ZitiVPNService: onCreate()
10-31 22:28:19.140 31012 13692 I ZitiVPNService: command monitor started
10-31 22:28:19.140 31012 13692 I ZitiVPNService: received cmd[stop]
10-31 22:28:19.140 31012 13692 I ZitiVPNService: tunnel stop success
10-31 22:28:19.140 31012 13692 I ZitiVPNService: monitoring route updates
10-31 22:28:19.140 31012  5108 I ZitiVPNService: network available: 110, caps:[ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&VALIDATED&NOT_ROAMING&FOREGROUND&NOT_CONGESTED&NOT_SUSPENDED LinkUpBandwidth>=321960Kbps LinkDnBandwidth>=338906Kbps SignalStrength: -59 AdministratorUids: [] RequestorUid: -1 RequestorPackageName: null]
10-31 22:28:19.141 31012  5108 I ZitiVPNService: active[110]
10-31 22:28:19.141 31012  5108 I ZitiVPNService: link change[110], active[110]
10-31 22:28:19.142 31012  5108 I ZitiVPNService: link[110] addresses: [/192.168.4.11, /xxxx:xxxx:xxxx:xxxx:e0e6:77b5:e864:8300, /xxxx:xxxx:xxxx:xxxx:e8f2:76f6:e994:2c62]
10-31 22:28:19.142 31012  5108 I ZitiVPNService: link[110] nameservers: [/192.168.4.250]
10-31 22:28:19.142 31012  5108 I ZitiVPNService: set upstream DNS[[192.168.4.250]]
10-31 22:28:19.142 31012  5108 D Tunnel  : cmd[126] = SetUpstreamDNS:[{"host":"192.168.4.250"}]
10-31 22:28:19.143 31012  5089 I tunnel-cbs:ziti_dns.c:273 ziti_dns_set_upstream(): DNS upstream[1] is set to 192.168.4.250:53
10-31 22:28:19.143 31012  5089 I Tunnel  : resp = {"Success":true,"Code":0}
10-31 22:28:19.143 31012  5089 D Tunnel  : result[126] = SetUpstreamDNS:TunnelResult(success=true, code=0, error=null, data=null)
10-31 22:28:26.824 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:28:32.350 31012 31012 I ZitiVPNService: onDestroy
10-31 22:28:32.351 31012 13692 I ZitiVPNService: stopped route updates
10-31 22:28:32.362 31012 31012 W TabLayout: MODE_SCROLLABLE + GRAVITY_FILL is not supported, GRAVITY_START will be used instead
10-31 22:28:46.845 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
8

I have been dealing with connectivity issues, and somewhat covered in this thread

I noticed that my android devices were unable to connect, but other tunnels, including new users (on android) connect perfectly.

I arrived here by noticing the subject_token is invalid error line in the controller logs.

I am running GrapheneOS, and I have Ziti Mobile Edge installed directly from GitHub via Obtainium.

Other users are running stock Android, and they exhibit no issues.

I have both the controller and router installed via helm.

I inspected the ConfigMap for the controller, and the OIDC section is blank:

  - binding: edge-oidc
    options: { }

I have been debugging this from every angle, and I am curious if there is something specific about the release directly from GitHub, or using GrapheneOS, or both.

This has been a recent failure, and it is quite maddening.

At this point, I think my upgrading the controller and router was not the issue, and feeling that the upgrade was the issue is a red herring. At the very least, it may have set all of this in motion.

My instinct tells me that it is something about a direct install and/or GrapheneOS.

Why it recently stopped functioning out of nowhere is something I have not been able to deduce.

9

One additional note, in the Android tunnel logs, I noticed this:

api_session is partially authenticated, can't submit posture responses
10

I’m using LineageOS and it recently stopped functioning out of nowhere.

I upgrade ziti binaries on controller and routers about a month ago

12 
10-31 22:21:30.313 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
10-31 22:21:50.351 31012  5089 D ziti-sdk:posture.c:192 ziti_send_posture_data(): ztx[2] api_session is partially authenticated, can't submit posture responses
13

This is probably because Google Play store releases are delayed compared to Github releases. Before Google Play gets a new ZME release it is tested via Beta program.

the current release process is as follows:
Github released -> Google Play (Alpha) -> Google Play (Beta) -> Google Play (Production/general availability)

14

That was the problem!
I started an issue here that will help to prevent things like this in the future: Release Cadence Pairing With GA · Issue #379 · openziti/ziti-tunnel-android · GitHub

15

Downgrading the apk I was able to authenticate again.

I'm abroad for a week and I really needed the android client to work.

And this has ben the major failure I experienced since installation.

16

Thanks for the config.

I have visually identified a potential bug that your config would trigger. @ekoby was asking some great questions that lead me to reading through it.

I am updating the integration tests today to verify the bug actually exists.

1 Like