jitsi-contrib/jitsi-helm

upgrade of helm chart always cause SEVERE: Failed to connect/login: SASLError using SCRAM-SHA-1: not-authorized

dmitry-mightydevops opened this issue ยท 12 comments

If I change any value in HELM chart and then do

# all commented stuff was taken from current Jitsi on our old development (haven"t worked)
publicURL: "https://jitsi.test.com"
tz: UTC
web:
  ingress:
    enabled: true
    annotations:
      kubernetes.io/ingress.class: "nginx"
      nginx.ingress.kubernetes.io/cors-allow-credentials: "true"
      nginx.ingress.kubernetes.io/cors-allow-headers: Accept,Authorization,Cache-Control,Content-Type,DNT,If-Modified-Since,Keep-Alive,Origin,User-Agent,X-CSRFToken,X-CustomHeader,X-Requested-With
      nginx.ingress.kubernetes.io/cors-allow-methods: GET, POST, PUT, PATCH, DELETE, OPTIONS
      nginx.ingress.kubernetes.io/cors-allow-origin: "*"
      nginx.ingress.kubernetes.io/enable-cors: "true"
      nginx.ingress.kubernetes.io/server-snippet: |-
        add_header X-Robots-Tag "noindex, nofollow, nosnippet, noarchive";
      cert-manager.io/cluster-issuer: "letsencrypt-prod"
    hosts:
    - host: jitsi.test.com
      paths: [ "/" ]
    tls:
    - hosts:
      - "jitsi.test.com"
      secretName: jitsi.test.com-crt
jvb:
  serice:
    enabled: true
    type: LoadBalancer
helm upgrade --install jitsi jitsi/jitsi-meet  \
    --create-namespace \
    --namespace vp \
    --values values.yaml

few pods restarted but not the jitsi-prosody-0

klo jitsi-jitsi-meet-jicofo-b76945f9c-bddjp


Aug 01, 2021 9:11:27 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Connected, JID= null
Aug 01, 2021 9:11:27 PM org.jitsi.utils.logging2.LoggerImpl log
SEVERE: Failed to connect/login: SASLError using SCRAM-SHA-1: not-authorized
org.jivesoftware.smack.sasl.SASLErrorException: SASLError using SCRAM-SHA-1: not-authorized
	at org.jivesoftware.smack.SASLAuthentication.authenticationFailed(SASLAuthentication.java:292)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.parsePackets(XMPPTCPConnection.java:1100)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.access$300(XMPPTCPConnection.java:1000)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader$1.run(XMPPTCPConnection.java:1016)
	at java.lang.Thread.run(Thread.java:748)

Aug 01, 2021 9:11:32 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Connected, JID= null
Aug 01, 2021 9:11:32 PM org.jitsi.utils.logging2.LoggerImpl log
SEVERE: Failed to connect/login: SASLError using SCRAM-SHA-1: not-authorized
org.jivesoftware.smack.sasl.SASLErrorException: SASLError using SCRAM-SHA-1: not-authorized
	at org.jivesoftware.smack.SASLAuthentication.authenticationFailed(SASLAuthentication.java:292)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.parsePackets(XMPPTCPConnection.java:1100)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.access$300(XMPPTCPConnection.java:1000)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader$1.run(XMPPTCPConnection.java:1016)
	at java.lang.Thread.run(Thread.java:748)

Aug 01, 2021 9:11:37 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Connected, JID= null
Aug 01, 2021 9:11:37 PM org.jitsi.utils.logging2.LoggerImpl log
SEVERE: Failed to connect/login: SASLError using SCRAM-SHA-1: not-authorized
org.jivesoftware.smack.sasl.SASLErrorException: SASLError using SCRAM-SHA-1: not-authorized
	at org.jivesoftware.smack.SASLAuthentication.authenticationFailed(SASLAuthentication.java:292)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.parsePackets(XMPPTCPConnection.java:1100)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader.access$300(XMPPTCPConnection.java:1000)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection$PacketReader$1.run(XMPPTCPConnection.java:1016)
	at java.lang.Thread.run(Thread.java:748)

After I delete the pod jitsi-prosody-0 things start working.

klo jitsi-jitsi-meet-jicofo-b76945f9c-bddjp

Aug 01, 2021 9:12:30 PM org.jitsi.utils.logging2.LoggerImpl log
SEVERE: Failed to connect/login: The following addresses failed: 'jitsi-prosody.vp.svc:5222' failed because: jitsi-prosody.vp.svc/172.20.187.209 exception: java.net.ConnectException: Connection refused (Connection refused)
org.jivesoftware.smack.SmackException$ConnectionException: The following addresses failed: 'jitsi-prosody.vp.svc:5222' failed because: jitsi-prosody.vp.svc/172.20.187.209 exception: java.net.ConnectException: Connection refused (Connection refused)
	at org.jivesoftware.smack.SmackException$ConnectionException.from(SmackException.java:278)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectUsingConfiguration(XMPPTCPConnection.java:619)
	at org.jivesoftware.smack.tcp.XMPPTCPConnection.connectInternal(XMPPTCPConnection.java:902)
	at org.jivesoftware.smack.AbstractXMPPConnection.connect(AbstractXMPPConnection.java:383)
	at org.jitsi.impl.protocol.xmpp.XmppProviderImpl.doConnect(XmppProviderImpl.java:202)
	at org.jitsi.retry.RetryStrategy$TaskRunner.run(RetryStrategy.java:167)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

Aug 01, 2021 9:12:35 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Connected, JID= null
Aug 01, 2021 9:12:35 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Joined the room.
Aug 01, 2021 9:12:35 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Set replyTimeout=PT15S
Aug 01, 2021 9:12:37 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Added brewery instance: jvbbrewery@internal-muc.meet.jitsi/jitsi-jitsi-meet-jvb-84fc6fb84b-t68qc
Aug 01, 2021 9:12:37 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Added new videobridge: Bridge[jid=jvbbrewery@internal-muc.meet.jitsi/jitsi-jitsi-meet-jvb-84fc6fb84b-t68qc, relayId=null, region=null, stress=0.00]
Aug 01, 2021 9:12:37 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Scheduled health-check task for: jvbbrewery@internal-muc.meet.jitsi/jitsi-jitsi-meet-jvb-84fc6fb84b-t68qc
Aug 01, 2021 9:12:40 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Focus request for room: aaaa@muc.meet.jitsi
Aug 01, 2021 9:12:40 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Created new conference, roomJid=aaaa@muc.meet.jitsi
Aug 01, 2021 9:12:40 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Joining aaaa@muc.meet.jitsi
Aug 01, 2021 9:12:41 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Chat room event Joined member=ChatMember[aaaa@muc.meet.jitsi/37068474, jid: null]@993118313
Aug 01, 2021 9:12:41 PM org.jitsi.utils.logging2.LoggerImpl log
WARNING: Focus role unknown
Aug 01, 2021 9:12:41 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Obtained focus role: OWNER
Aug 01, 2021 9:12:41 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Granted owner to 37068474
Aug 01, 2021 9:12:41 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Member joined:37068474
Aug 01, 2021 9:12:41 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Chat room event PresenceUpdated member=ChatMember[aaaa@muc.meet.jitsi/37068474, jid: 37068474-fefb-4d5b-9653-ab321a0a26e5@meet.jitsi/wG8wXwCp]@993118313
Aug 01, 2021 9:12:41 PM org.jitsi.utils.logging2.LoggerImpl log
INFO: Chat room event PresenceUpdated member=ChatMember[aaaa@muc.meet.jitsi/37068474, jid: 37068474-fefb-4d5b-9653-ab321a0a26e5@meet.jitsi/wG8wXwCp]@993118313

thanks,
Dmitry

/kind: bug

Have you solved it now? I had the same problem

One problem I have noticed is your typo in the jvb service serice -> service but this shouldn't be the cause.

Can you try deleting the prosody pod so that it recreates itself?

Have you solved it now? I had the same problem

Yes, but it's not ideal - you have to restart the pod *-prosody-0 manually then it gets working again. Means each HELM run implies downtime :(

I think the main problem is that only one prosody instance can run per shard. But I'm not 100% sure.

I think the issue is the following:

On upgrade, a new secret is generated for the jicofo user. The prosody container of course does not pick this up.

That means that ideally, on upgrade, you should pass the existing secret to the chart.

We had a similar issue with the PostreSQL database in AlekSIS, and here is what we did to solve it (in GitLab CI):

https://edugit.org/AlekSIS/official/AlekSIS/-/blob/master/ci/deploy/review.yml#L15

Probably, another possibility would be to let some job container be triggere dto change the jicofo user password.

Wouldn't adding an annotation or label to prosody pod make it redeploy itself when the secrets are changed?
I do a similar hack in one of my charts to force it to redeploy the app if I set the image pull policy to Always:

  template:
    metadata:
      labels:
        <...>
        {{- if eq .Values.image.pullPolicy "Always" }}
        com.example.some-app/image-tag: {{ .Values.image.tag | default .Chart.AppVersion | quote }}
        com.example.some-app/image-pull-timestamp: {{ now | date "20060102T150405" }}
        {{- end }}

This still happens every time on my deployment :(

spijet commented

Hello @perfectra1n!

Can you check that your Prosody instance is getting restarted/recreated after an update or redeploy?

Yeah it wasn't working, as the secrets were updated but the prosody Pod wasn't being killed/restarted. I opted to use Reloader and provide the reloader.stakater.com/auto: "true" annotation on the Deployment, and it's been working great ever since.
image

It looks like the fix for this issue got backed out with fe24af6. The timestamp check was replaced with two hash checks, however I'm running into the issue of prosody not restarting to pick up newly generated secrets every time this chart gets re-deployed by argo-cd (e.g. on a hard refresh). In that case, there have been no changes to any Values, so these hashes don't change and the prosody StatefulSet doesn't get re-deployed.

Unfortunately, it's very hard to do this properly because of two things:

  1. Prosody here is bundled as a subchart, and the relevant k8s secrets are actually rendered in a parent chart;
  2. The proper way of generating these hash annotations requires using the helm's File hooks (to read and render the values and secret templates as a separate entity and then hash it), which will not work inside a subchart AND in some CI/CD environments as well (not 100% sure, but I think I heard that ArgoCD doesn't do well with these hooks too).

It may work if we try to specify additional annotations in parent chart's values, but I'll need to test it out first. As for now, maybe we should revert to "now" timestamps instead. It will lead to redundant Prosody redeploys, but I think it's still better that what we have now.

@wrenix, WDYT?