Help please! Recording failed: Prosody configuration shot after update to 11.6

Still looking for why jibris stopped working.
Jicofo log on the jitsi server shows unexpected status is received in response to start iq on focus… So jibri does not start.

In prosody.log I find the following:

Sep 12 07:35:02 certmanager error SSL/TLS: Failed to load ‘/etc/prosody/certs/localhost.key’: Check that the permissions allow Prosody to read this file. (for localhost)
Sep 12 07:35:02 localhost:tls error Error creating context for c2s: error loading private key (Permission denied)

Prosody.error is also attached. Not sure what this means. I suspect the localhost.crt is not what it should be looking for. Could this have been changed by updates on Prosody? I now have Prosody version 11.6 which happened as part of apt update and apt upgrade after I updated to 11.5 to enable speaker stats. Things where still working then.

@Plokta suggested prosodyctl check on April 6th in https://community.jitsi.org/t/need-help-to-update-prosody-to-0-11/30219/10
Error messages show something needs correcting, but I am not sure how to go about it. How do I get rid of these error logs? Can somebody please help?

Thanks for your efforts

Norbert

jicofolog 12092020.txt (2.4 KB)


prosody.log.12092020.log (10.3 KB) prosody.err.12092020.log (4.3 KB)

Is there any jibri logs when this happens?

You have a miising module in lua 5.2 usr/lib/prosody/util/startup.lua:199: module ‘net.url’ not found:
Install it using luarocks

Hi Damencho,
Thanks for looking into this. Here is the current log.
jibri12092020.log (3.2 KB)

Will check how to install module net.url and luarocks.
Norbert

No joy, Downloaded and installed luarocks, unzipped, installed, no change. :disappointed: No token stuff installed anyway.
What is it with the permissions and local key and certificate? Would net.url fix that? Shouldn’t prosody refer to the certificates of the jitsi server instead?
And what about the references to a loclahost IP address for jibri? That’s most puzzling!
There is so much I don’t understand, so many questions. I’ll keep looking.
Norbert

Cert thing you can ignore, you can remove localhost config from prosody and that will be gone, I suspect you have lua 5.2 and 5.1 and thats your problem, you install through luarocks but that is only for 5.1, I think I had fixed those problems with https://stackoverflow.com/questions/20321560/how-do-install-libraries-for-both-lua5-2-and-5-1-using-luarocks

Hi Damencho,
Thanks for your thoughts and link. I checked in /usr/local/bin/: listing shows:
lrwxrwxrwx 1 root root 12 Sep 12 17:14 luarocks -> luarocks-5.2
-rwxr-xr-x 1 root root 885 Sep 12 17:14 luarocks-5.2
lrwxrwxrwx 1 root root 18 Sep 12 17:14 luarocks-admin -> luarocks-admin-5.2
-rwxr-xr-x 1 root root 481 Sep 12 17:14 luarocks-admin-5.2

I did a standard install of jitsi from stable in April, which had prosody version 9, then upgraded using the guidelines on the community forum. Added speaker stats and session length display which works.
Only registered user on prosody can start meetings, and that works fine. The only thing that does not work is recording. Is there any other place where I can check if luarocks1 might be lurking and cuase trouble?

As I still feel fairly inexperienced, could you guide me towards how to remove the localhost config from prosody? Any pointers are really appreciated very much. Thanks for your understanding and support.

Norbert

In /etc/prosody/conf.d/localhost… Should be a link, just remove the link

And you are installing the missing lib with luarocks-5. 2, right?

Hi Damian,

Thanks. I have removed the link.

I followed instructions to install luarocks-5.2 and the module as suggested. I get:

Installing https://luarocks.org/net-url-0.9-1.src.rock

net-url 0.9-1 is now installed in /usr/local (license: MIT/X11)

After reboot on prosodyctl check I still get:

root@jitsi:~# prosodyctl check

certmanager error SSL/TLS: Failed to load ‘/etc/prosody/certs/localhost.key’: Check that the permissions allow Prosody to read this file. (for client_https port 0)

Still get:

Despite the lack of an error message when installing net-url, the listing of modules installed only lists the following:

root@jitsi:/usr/lib/prosody/modules# ls -la

total 568

drwxr-xr-x 7 root root 12288 Sep 10 07:42 .

drwxr-xr-x 6 root root 4096 Sep 10 07:42 …

drwxr-xr-x 2 root root 4096 Sep 10 07:42 adhoc

-rw-r–r-- 1 root root 34207 Aug 1 12:58 mod_admin_adhoc.lua

-rw-r–r-- 1 root root 47054 Aug 1 12:58 mod_admin_telnet.lua

-rw-r–r-- 1 root root 3099 Aug 1 12:58 mod_announce.lua

-rw-r–r-- 1 root root 1886 Aug 1 12:58 mod_auth_anonymous.lua

-rw-r–r-- 1 root root 2448 Aug 1 12:58 mod_auth_cyrus.lua

-rw-r–r-- 1 root root 1592 Aug 1 12:58 mod_auth_insecure.lua

-rw-r–r-- 1 root root 4902 Aug 1 12:58 mod_auth_internal_hashed.lua

-rw-r–r-- 1 root root 2417 Aug 1 12:58 mod_auth_internal_plain.lua

-rw-r–r-- 1 root root 11175 Aug 1 12:58 mod_blocklist.lua

-rw-r–r-- 1 root root 18743 Aug 1 12:58 mod_bosh.lua

-rw-r–r-- 1 root root 11243 Aug 1 12:58 mod_c2s.lua

-rw-r–r-- 1 root root 4176 Aug 1 12:58 mod_carbons.lua

-rw-r–r-- 1 root root 12151 Aug 1 12:58 mod_component.lua

-rw-r–r-- 1 root root 627 Aug 1 12:58 mod_csi.lua

-rw-r–r-- 1 root root 2973 Aug 1 12:58 mod_csi_simple.lua

-rw-r–r-- 1 root root 448 Aug 1 12:58 mod_debug_sql.lua

-rw-r–r-- 1 root root 7719 Aug 1 12:58 mod_dialback.lua

-rw-r–r-- 1 root root 8801 Aug 1 12:58 mod_disco.lua

-rw-r–r-- 1 root root 3839 Aug 1 12:58 mod_groups.lua

-rw-r–r-- 1 root root 1991 Aug 1 12:58 mod_http_errors.lua

-rw-r–r-- 1 root root 5863 Aug 1 12:58 mod_http_files.lua

-rw-r–r-- 1 root root 6773 Aug 1 12:58 mod_http.lua

-rw-r–r-- 1 root root 2387 Aug 1 12:58 mod_iq.lua

-rw-r–r-- 1 root root 1490 Aug 1 12:58 mod_lastactivity.lua

-rw-r–r-- 1 root root 3316 Aug 1 12:58 mod_legacyauth.lua

-rw-r–r-- 1 root root 3206 Aug 1 12:58 mod_limits.lua

drwxr-xr-x 2 root root 4096 Sep 10 07:42 mod_mam

-rw-r–r-- 1 root root 2320 Aug 1 12:58 mod_message.lua

-rw-r–r-- 1 root root 873 Aug 1 12:58 mod_motd.lua

-rw-r–r-- 1 root root 14709 Aug 1 12:58 mod_muc_mam.lua

-rw-r–r-- 1 root root 486 Aug 1 12:58 mod_muc_unique.lua

-rw-r–r-- 1 root root 1960 Aug 1 12:58 mod_net_multiplex.lua

-rw-r–r-- 1 root root 1149 Aug 1 12:58 mod_offline.lua

-rw-r–r-- 1 root root 13760 Aug 1 12:58 mod_pep.lua

-rw-r–r-- 1 root root 145 Aug 1 12:58 mod_pep_plus.lua

-rw-r–r-- 1 root root 11481 Aug 1 12:58 mod_pep_simple.lua

-rw-r–r-- 1 root root 909 Aug 1 12:58 mod_ping.lua

-rw-r–r-- 1 root root 5669 Aug 1 12:58 mod_posix.lua

-rw-r–r-- 1 root root 15031 Aug 1 12:58 mod_presence.lua

-rw-r–r-- 1 root root 1447 Aug 1 12:58 mod_private.lua

-rw-r–r-- 1 root root 7346 Aug 1 12:58 mod_proxy65.lua

drwxr-xr-x 2 root root 4096 Sep 10 07:42 mod_pubsub

-rw-r–r-- 1 root root 7335 Aug 1 12:58 mod_register_ibr.lua

-rw-r–r-- 1 root root 2917 Aug 1 12:58 mod_register_limits.lua

-rw-r–r-- 1 root root 407 Aug 1 12:58 mod_register.lua

-rw-r–r-- 1 root root 5089 Aug 1 12:58 mod_roster.lua

drwxr-xr-x 2 root root 4096 Sep 10 07:42 mod_s2s

-rw-r–r-- 1 root root 1659 Aug 1 12:58 mod_s2s_auth_certs.lua

-rw-r–r-- 1 root root 12113 Aug 1 12:58 mod_saslauth.lua

-rw-r–r-- 1 root root 3579 Aug 1 12:58 mod_scansion_record.lua

-rw-r–r-- 1 root root 1243 Aug 1 12:58 mod_server_contact_info.lua

-rw-r–r-- 1 root root 666 Aug 1 12:58 mod_stanza_debug.lua

-rw-r–r-- 1 root root 5397 Aug 1 12:58 mod_storage_internal.lua

-rw-r–r-- 1 root root 5796 Aug 1 12:58 mod_storage_memory.lua

-rw-r–r-- 1 root root 699 Aug 1 12:58 mod_storage_none.lua

-rw-r–r-- 1 root root 21077 Aug 1 12:58 mod_storage_sql.lua

-rw-r–r-- 1 root root 6615 Aug 1 12:58 mod_storage_xep0227.lua

-rw-r–r-- 1 root root 1264 Aug 1 12:58 mod_time.lua

-rw-r–r-- 1 root root 5930 Aug 1 12:58 mod_tls.lua

-rw-r–r-- 1 root root 117 Aug 1 12:58 mod_unknown.lua

-rw-r–r-- 1 root root 1481 Aug 1 12:58 mod_uptime.lua

-rw-r–r-- 1 root root 3043 Aug 1 12:58 mod_user_account_management.lua

-rw-r–r-- 1 root root 1625 Aug 1 12:58 mod_vcard4.lua

-rw-r–r-- 1 root root 11424 Aug 1 12:58 mod_vcard_legacy.lua

-rw-r–r-- 1 root root 1462 Aug 1 12:58 mod_vcard.lua

-rw-r–r-- 1 root root 1273 Aug 1 12:58 mod_version.lua

-rw-r–r-- 1 root root 1229 Aug 1 12:58 mod_watchregistrations.lua

-rw-r–r-- 1 root root 11490 Aug 1 12:58 mod_websocket.lua

-rw-r–r-- 1 root root 690 Aug 1 12:58 mod_welcome.lua

-rw-r–r-- 1 root root 88 Aug 1 12:58 mod_windows.lua

drwxr-xr-x 2 root root 4096 Sep 10 07:42 muc

What next?

Norbert

Do you still see the error abou net url in prosody logs?

That module is a lua one, not prosody… It goes in some lua common folder

My question was that you install the net url using luarocks-5.2 install ... right?

Dear Damian,

I tried another recording with recording failing, and the prosody log is as follows now:

Sep 12 21:44:30 c2s250dba0 info Client connected

Sep 12 21:44:32 c2s250dba0 info Client disconnected: connection closed

Sep 12 21:53:30 conference.jitsi.ngberger.com:muc_domain_mapper warn Session filters applied

Sep 12 21:53:30 mod_bosh info New BOSH session, assigned it sid ‘ce760d38-2e30-437d-b09f-fdbcd79592a6’

Sep 12 21:53:30 boshce760d38-2e30-437d-b09f-fdbcd79592a6 info Authenticated as pfv9l6i06tvewgw7@guest.jitsi.ngberger.com

Sep 12 21:53:46 conference.jitsi.ngberger.com:muc_domain_mapper warn Session filters applied

Sep 12 21:53:46 mod_bosh info New BOSH session, assigned it sid ‘e05390c1-bf75-4ef2-9190-73c5dc4e8de4’

Sep 12 21:53:46 boshe05390c1-bf75-4ef2-9190-73c5dc4e8de4 info Authenticated as tfj2os9foi6jg59u@guest.jitsi.ngberger.com

Sep 12 21:54:04 boshce760d38-2e30-437d-b09f-fdbcd79592a6 info BOSH client disconnected: session close

Sep 12 21:54:10 speakerstats.jitsi.ngberger.com:speakerstats_component warn A module has been configured that triggers external events.

Sep 12 21:54:10 speakerstats.jitsi.ngberger.com:speakerstats_component warn Implement this lib to trigger external events.

Sep 12 21:54:10 boshe05390c1-bf75-4ef2-9190-73c5dc4e8de4 info BOSH client disconnected: session close

So the net url error seems to be gone.

Norbert

And the jicofo log is:

Jicofo 2020-09-12 21:53:34.192 INFO: [74] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: negotiating25062020@conference.jitsi.ngberger.com

Jicofo 2020-09-12 21:53:34.192 INFO: [74] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Authenticated jid: pfv9l6i06tvewgw7@guest.jitsi.ngberger.com/yKiZbbku with session: AuthSession[$

Jicofo 2020-09-12 21:53:34.192 INFO: [74] org.jitsi.jicofo.auth.AbstractAuthAuthority.log() Jid pfv9l6i06tvewgw7@guest.jitsi.ngberger.com/yKiZbbku authenticated as: ngberger@jitsi.ngberger$

Jicofo 2020-09-12 21:53:34.193 INFO: [74] org.jitsi.jicofo.FocusManager.log() Created new focus for negotiating25062020@conference.jitsi.ngberger.com@auth.jitsi.ngberger.com. Conference co$

Jicofo 2020-09-12 21:53:34.193 INFO: [74] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Joining the room: negotiating25062020@conference.jitsi.ngberger.com

Jicofo 2020-09-12 21:53:34.267 INFO: [30] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.proto$

Jicofo 2020-09-12 21:53:34.271 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member negotiating25062020@conference.jitsi.ngberger.com/ad3741a7 joined.

Jicofo 2020-09-12 21:53:47.655 INFO: [81] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: negotiating25062020@conference.jitsi.ngberger.com

Jicofo 2020-09-12 21:53:49.085 INFO: [46] org.jitsi.jicofo.xmpp.FocusComponent.log() Focus request for room: negotiating25062020@conference.jitsi.ngberger.com

Jicofo 2020-09-12 21:53:49.207 INFO: [30] org.jitsi.jicofo.ChatRoomRoleAndPresence.log() Chat room event ChatRoomMemberPresenceChangeEvent[type=MemberJoined sourceRoom=org.jitsi.impl.proto$

Jicofo 2020-09-12 21:53:49.208 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Member negotiating25062020@conference.jitsi.ngberger.com/adce6424 joined.

Jicofo 2020-09-12 21:53:49.216 INFO: [30] org.jitsi.jicofo.bridge.BridgeSelectionStrategy.log() Selected initial bridge Bridge[jid=jvbbrewery@internal.auth.jitsi.ngberger.com/907602a9-dcbe$

Jicofo 2020-09-12 21:53:49.230 INFO: [30] org.jitsi.impl.protocol.xmpp.colibri.OperationSetColibriConferenceImpl.log() Conference created: org.jitsi.impl.protocol.xmpp.colibri.ColibriConfe$

Jicofo 2020-09-12 21:53:49.232 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= negotiating25062020@conference.jitsi.ngberger.com/ad3741a7, bridge=jvbbrewer$

Jicofo 2020-09-12 21:53:49.233 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=60516 octo_enabled= false: [[null, null]]

Jicofo 2020-09-12 21:53:49.235 INFO: [285] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for negotiating25062020@conference.jitsi.ngberger.com/ad3741a7

Jicofo 2020-09-12 21:53:49.236 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Added participant jid= negotiating25062020@conference.jitsi.ngberger.com/adce6424, bridge=jvbbrewer$

Jicofo 2020-09-12 21:53:49.236 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Region info, conference=60516 octo_enabled= false: [[null, null, null]]

Jicofo 2020-09-12 21:53:49.236 INFO: [287] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Doing feature discovery for negotiating25062020@conference.jitsi.ngberger.com/adce6424

Jicofo 2020-09-12 21:53:49.835 INFO: [285] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for negotiating25062020@conference.jitsi.ngberger.com/ad3741a7 in$

Jicofo 2020-09-12 21:53:49.868 INFO: [285] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.jitsi.ngberger.com/907602a9-dcbe-4cbf-84ac-619fe96695c9 to allocat$

Jicofo 2020-09-12 21:53:49.953 INFO: [285] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: negotiating25062020@conference.jitsi.ngberger.com/ad3741a7

Jicofo 2020-09-12 21:53:50.356 INFO: [287] org.jitsi.jicofo.discovery.DiscoveryUtil.log() Successfully discovered features for negotiating25062020@conference.jitsi.ngberger.com/adce6424 in$

Jicofo 2020-09-12 21:53:50.357 INFO: [287] org.jitsi.jicofo.AbstractChannelAllocator.log() Using jvbbrewery@internal.auth.jitsi.ngberger.com/907602a9-dcbe-4cbf-84ac-619fe96695c9 to allocat$

Jicofo 2020-09-12 21:53:50.378 INFO: [287] org.jitsi.jicofo.ParticipantChannelAllocator.log() Sending session-initiate to: negotiating25062020@conference.jitsi.ngberger.com/adce6424

Jicofo 2020-09-12 21:53:50.424 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: negotiating25062020@conference.jitsi.ngberger.com/ad3741a7

Jicofo 2020-09-12 21:53:50.438 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from negotiating25062020@conference.jitsi.ngberger.com/ad3741a7 with accept$

Jicofo 2020-09-12 21:53:50.452 WARNING: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() No jingle session yet for negotiating25062020@conference.jitsi.ngberger.com/adce6424

Jicofo 2020-09-12 21:53:51.205 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Got session-accept from: negotiating25062020@conference.jitsi.ngberger.com/adce6424

Jicofo 2020-09-12 21:53:51.210 INFO: [30] org.jitsi.jicofo.JitsiMeetConferenceImpl.log() Received session-accept from negotiating25062020@conference.jitsi.ngberger.com/adce6424 with accept$

Jicofo 2020-09-12 21:53:51.213 INFO: [30] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.log() Notify add SSRC negotiating25062020@conference.jitsi.ngberger.com/ad3741a7 SID: 31mi6a14s$

Jicofo 2020-09-12 21:53:51.214 INFO: [30] org.jitsi.protocol.xmpp.AbstractOperationSetJingle.log() Notify add SSRC negotiating25062020@conference.jitsi.ngberger.com/adce6424 SID: 9v4n78s0l$

Jicofo 2020-09-12 21:53:58.791 INFO: [31] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting session with Jibri jibribrewery@internal.auth.jitsi.ngberger.com/jibri0

Jicofo 2020-09-12 21:53:58.791 INFO: [31] org.jitsi.jicofo.recording.jibri.JibriSession.log() Starting Jibri jibribrewery@internal.auth.jitsi.ngberger.com/jibri0 for stream ID: null in roo$

Jicofo 2020-09-12 21:53:59.089 SEVERE: [31] org.jitsi.jicofo.recording.jibri.JibriSession.log() Unexpected status received in response to the start IQ: <iq to='focus@auth.jitsi.ngberger.co$

Jicofo 2020-09-12 21:53:59.089 SEVERE: [31] org.jitsi.jicofo.recording.jibri.JibriSession.log() Failed to send start Jibri IQ: org.jitsi.jicofo.recording.jibri.JibriSession$StartException:$

org.jitsi.jicofo.recording.jibri.JibriSession$StartException: Unexpected response

at org.jitsi.jicofo.recording.jibri.JibriSession.sendJibriStartIq(JibriSession.java:595)

at org.jitsi.jicofo.recording.jibri.JibriSession.startInternal(JibriSession.java:370)

at org.jitsi.jicofo.recording.jibri.JibriSession.start(JibriSession.java:335)

Norbert

Are the users registered?

find /var/lib/prosody -name "*.dat"

Yes, Emrah. User registrations have not changed since upgrades. All the users I registered are listed, including focus, jibri, recorder and hosts of meetings
Norbert

Any ideas anyone?