Panic when deleting expired session #406
Description
Today one of our yivi servers (version 0.16.0) panicked when a session expired:
Mar 20 11:37:18 ilab1-pubhubs docker[3983163]: time="2025-03-20T11:37:18Z" level=info msg="Deleting expired session" session=RNAvpfjtb2bkWFInIs1U
Mar 20 11:37:18 ilab1-pubhubs docker[3983163]: panic: send on closed channel
Mar 20 11:37:18 ilab1-pubhubs docker[3983163]: goroutine 1598 [running]:
Mar 20 11:37:18 ilab1-pubhubs docker[3983163]: github.com/privacybydesign/irmago/server/irmaserver.(*memorySessionStore).handleTransaction.func1()
Mar 20 11:37:18 ilab1-pubhubs docker[3983163]: /go/irmago/server/irmaserver/sessions.go:185 +0x68
Mar 20 11:37:18 ilab1-pubhubs docker[3983163]: created by github.com/privacybydesign/irmago/server/irmaserver.(*memorySessionStore).handleTransaction in goroutine 1597
Mar 20 11:37:18 ilab1-pubhubs docker[3983163]: /go/irmago/server/irmaserver/sessions.go:183 +0x468
Not sure what happened to trigger this, so I do not know how to reproduce this error. Perhaps the cause can be inferred from the code.
The full log of the yivi server:
time="2025-03-20T11:10:44Z" level=info msg="irma server running" mode=production verbosity=info version=0.16.0
time="2025-03-20T11:10:44Z" level=info msg="No configuration file found"
time="2025-03-20T11:10:44Z" level=info msg="Determined schemes path" schemes_path="/root/.local/share/irma/irma_configuration"
time="2025-03-20T11:10:44Z" level=info msg="No schemes found in /root/.local/share/irma/irma_configuration, downloading default (irma-demo and pbdf)"
time="2025-03-20T11:10:44Z" level=info msg="downloading default schemes (may take a while)"
time="2025-03-20T11:10:44Z" level=info msg="checking for updates" scheme=irma-demo type=issuer
time="2025-03-20T11:10:44Z" level=info msg="scheme is outdated, updating" scheme=irma-demo type=issuer
time="2025-03-20T11:10:47Z" level=info msg="checking for updates" scheme=pbdf type=issuer
time="2025-03-20T11:10:47Z" level=info msg="scheme is outdated, updating" scheme=pbdf type=issuer
time="2025-03-20T11:10:48Z" level=info msg="Finished downloading schemes"
time="2025-03-20T11:10:48Z" level=info msg="Updating schemes every 60 minutes"
time="2025-03-20T11:10:48Z" level=warning msg="No url parameter specified in configuration; unless an url is elsewhere prepended in the QR, the IRMA client will not be able to connect"
time="2025-03-20T11:10:48Z" level=info msg="checking for updates" scheme=irma-demo type=issuer
time="2025-03-20T11:10:48Z" level=warning msg="Revocation-supporting private key installed for irma-demo.uzipoc-cibg.uzi-proeftuin, but no revocation server is configured: issuance sessions will always fail"
time="2025-03-20T11:10:48Z" level=warning msg="Revocation-supporting private key installed for irma-demo.inz-id-card.idCard, but no revocation server is configured: issuance sessions will always fail"
time="2025-03-20T11:10:48Z" level=warning msg="Revocation-supporting private key installed for irma-demo.MijnOverheid.root, but no revocation server is configured: issuance sessions will always fail"
time="2025-03-20T11:10:48Z" level=warning msg="Revocation-supporting private key installed for irma-demo.inz-revocable-id.id, but no revocation server is configured: issuance sessions will always fail"
time="2025-03-20T11:10:48Z" level=warning msg="Revocation-supporting private key installed for irma-demo.amsterdamVorin.taxiZoneExemption, but no revocation server is configured: issuance sessions will always fail"
time="2025-03-20T11:10:48Z" level=warning msg="Revocation-supporting private key installed for irma-demo.uzipoc-cibg.uzi-acceptance, but no revocation server is configured: issuance sessions will always fail"
time="2025-03-20T11:10:48Z" level=warning msg="Revocation-supporting private key installed for irma-demo.uzipoc-cibg.uzi-2, but no revocation server is configured: issuance sessions will always fail"
time="2025-03-20T11:10:48Z" level=info msg="scheme is up-to-date, not updating" scheme=irma-demo type=issuer
time="2025-03-20T11:10:48Z" level=info msg="checking for updates" scheme=pbdf type=issuer
time="2025-03-20T11:10:48Z" level=info msg="scheme is up-to-date, not updating" scheme=pbdf type=issuer
time="2025-03-20T11:10:48Z" level=warning msg="Authentication of incoming session requests disabled: anyone who can reach this server can use it"
time="2025-03-20T11:10:48Z" level=info msg="Server listening at 0.0.0.0:8089/"
time="2025-03-20T11:10:48Z" level=info msg="Client server listening at 0.0.0.0:8088/"
time="2025-03-20T11:10:48Z" level=info msg="checking for updates" scheme=irma-demo type=issuer
time="2025-03-20T11:10:48Z" level=info msg="scheme is up-to-date, not updating" scheme=irma-demo type=issuer
time="2025-03-20T11:10:48Z" level=info msg="checking for updates" scheme=pbdf type=issuer
time="2025-03-20T11:10:48Z" level=info msg="scheme is up-to-date, not updating" scheme=pbdf type=issuer
time="2025-03-20T11:26:50Z" level=info msg="Session started" action=disclosing session=VsCEdhKiNkhRFZwcDtyl
time="2025-03-20T11:26:50Z" level=info msg="Session request (purged of attribute values): {"validity":120,"request":{"@context":"https://irma.app/ld/request/disclosure/v2","context":"AQ==","nonce":"htgo8Zl51DQMSaQvfERkSw==","disclose":[[["pbdf.sidn-pbdf.email.domain"]]]}}" session=VsCEdhKiNkhRFZwcDtyl
time="2025-03-20T11:26:57Z" level=info msg="Session updated" session=VsCEdhKiNkhRFZwcDtyl status=CONNECTED
time="2025-03-20T11:27:04Z" level=info msg="Session updated" session=VsCEdhKiNkhRFZwcDtyl status=DONE
time="2025-03-20T11:27:09Z" level=info msg="Session started" action=disclosing session=2x5q9eOyiToCkRcvEdpB
time="2025-03-20T11:27:09Z" level=info msg="Session request (purged of attribute values): {"validity":120,"request":{"@context":"https://irma.app/ld/request/disclosure/v2","context":"AQ==","nonce":"iCWmiRReY2amWdq93m0obw==","disclose":[[["pbdf.sidn-pbdf.email.domain"]]]}}" session=2x5q9eOyiToCkRcvEdpB
time="2025-03-20T11:27:38Z" level=info msg="Session started" action=disclosing session=09IP30hXMtVW6LZa5mTo
time="2025-03-20T11:27:38Z" level=info msg="Session request (purged of attribute values): {"validity":120,"request":{"@context":"https://irma.app/ld/request/disclosure/v2","context":"AQ==","nonce":"2Ua9dKUmQ8s8s6RZMCRF1Q==","disclose":[[["pbdf.sidn-pbdf.email.domain"]]]}}" session=09IP30hXMtVW6LZa5mTo
time="2025-03-20T11:30:17Z" level=info msg="Session started" action=disclosing session=RNAvpfjtb2bkWFInIs1U
time="2025-03-20T11:30:17Z" level=info msg="Session request (purged of attribute values): {"validity":120,"request":{"@context":"https://irma.app/ld/request/disclosure/v2","context":"AQ==","nonce":"jyBympSW30MPkQJ8vA7caQ==","disclose":[[["pbdf.sidn-pbdf.email.domain"]]]}}" session=RNAvpfjtb2bkWFInIs1U
time="2025-03-20T11:32:06Z" level=info msg="Session updated" session=RNAvpfjtb2bkWFInIs1U status=CONNECTED
time="2025-03-20T11:32:08Z" level=info msg="Deleting expired session" session=VsCEdhKiNkhRFZwcDtyl
time="2025-03-20T11:32:15Z" level=info msg="Session updated" session=RNAvpfjtb2bkWFInIs1U status=DONE
time="2025-03-20T11:34:02Z" level=info msg="Session started" action=disclosing session=RuQtLUGgEZ7FrjAVuzU1
time="2025-03-20T11:34:02Z" level=info msg="Session request (purged of attribute values): {"validity":120,"request":{"@context":"https://irma.app/ld/request/disclosure/v2","context":"AQ==","nonce":"E0bULoE4ulnJh1eccHZ/aw==","disclose":[[["pbdf.sidn-pbdf.email.domain"]]]}}" session=RuQtLUGgEZ7FrjAVuzU1
time="2025-03-20T11:34:58Z" level=warning msg="Sending session error" description="Unexpected request in this state" error=UNEXPECTED_REQUEST message="Session already started" status=403
time="2025-03-20T11:34:58Z" level=info msg="Session updated" session=RNAvpfjtb2bkWFInIs1U status=DONE
time="2025-03-20T11:34:58Z" level=warning msg="<= response" duration="402.575µs" status=403 url="/irma/session/kWU1UtPsO34IXsQy9Qtz/"
time="2025-03-20T11:37:18Z" level=info msg="Deleting expired session" session=RNAvpfjtb2bkWFInIs1U
panic: send on closed channel
goroutine 1598 [running]:
github.com/privacybydesign/irmago/server/irmaserver.(*memorySessionStore).handleTransaction.func1()
/go/irmago/server/irmaserver/sessions.go:185 +0x68
created by github.com/privacybydesign/irmago/server/irmaserver.(*memorySessionStore).handleTransaction in goroutine 1597
/go/irmago/server/irmaserver/sessions.go:183 +0x468