Hello,
I am trying to to set up OpenMeetings on an AWS EC2 instance running
Ubuntu Jammy. All goes well until I reach page 11 of the web wizard.
When I get to checking for "OpenOffice/LibreOffice Path for
jodconvertor" the page hangs. My ssh console becomes unresponsive for a
few minutes. When it finally recovers I can see that tomcat has died.
This is what the logs show.
DEBUG 07-19 08:36:00.255 o.a.o.u.p.ProcessHelper:81 [nio-5443-exec-4] -
START view:soxPath path:: '' #################
DEBUG 07-19 08:36:00.263 o.a.o.u.p.ProcessHelper:82 [nio-5443-exec-4] -
sox --version
DEBUG 07-19 08:36:00.277 o.a.o.u.p.ProcessHelper:88 [nio-5443-exec-4] -
END view:soxPath path:: '' #################
DEBUG 07-19 08:36:13.285 o.a.o.u.c.CryptProvider:36 [Bean#0_Worker-6] -
get:: configKeyCryptClassName: null
It starts looking for the office path.
INFO 07-19 08:36:27.942 o.j.c.o.AbstractOfficeManagerPool:142
[nio-5443-exec-6] - Stopping the office manager pool...
INFO 07-19 08:36:27.943 o.j.l.o.OfficeDescriptor:100 [er-offprocmng-0]
- soffice info (from exec path): Product: LibreOffice - Version: ??? -
useLongOptionNameGnuStyle: true
DEBUG 07-19 08:36:28.288 o.a.o.u.c.CryptProvider:36 [Bean#0_Worker-2] -
get:: configKeyCryptClassName: null
INFO 07-19 08:36:28.678 o.j.l.o.OfficeDescriptor:75 [er-offprocmng-0]
- soffice info (from help output): Product: LibreOffice - Version:
7.3.4.2 - useLongOptionNameGnuStyle: true
It finds it and then tries to start jod convertor (I think).
INFO 07-19 08:36:28.700 o.j.l.o.LocalOfficeProcessManager:395
[er-offprocmng-0] - Starting process with --accept
'socket,host=127.0.0.1,port=2002,tcpNoDelay=1;urp;StarOffice.ServiceManager'
and profileDir
'/home/ubuntu/apache-openmeetings-6.3.0/temp/.jodconverter_socket_host-127.0.0.1_port-2002_tcpNoDelay-1'
WARN 07-19 08:36:35.488 o.j.l.o.StartProcessAndConnectRetryable:144
[er-offprocmng-0] - Office process died with exit code 81; restarting it
It fails and tries again.
WARN 07-19 08:37:18.086 c.h.i.c.i.ClusterHeartbeatManager:67
[cached.thread-7] - [172.31.47.17]:5701 [dev] [5.1.1] Resetting
heartbeat timestamps because of huge system clock jump! Clock-Jump:
35697 ms, Heartbeat-Timeout: 60000 ms
DEBUG 07-19 08:37:18.087 o.a.o.u.c.CryptProvider:36 [Bean#0_Worker-7] -
get:: configKeyCryptClassName: null
WARN 07-19 08:38:42.196 c.h.i.c.i.ClusterHeartbeatManager:67
[ached.thread-16] - [172.31.47.17]:5701 [dev] [5.1.1] Resetting
heartbeat timestamps because of huge system clock jump! Clock-Jump:
74197 ms, Heartbeat-Timeout: 60000 ms
DEBUG 07-19 08:38:42.122 o.a.o.u.c.CryptProvider:36 [ean#0_Worker-10] -
get:: configKeyCryptClassName: null
DEBUG 07-19 08:39:19.731 o.a.o.u.c.CryptProvider:36 [Bean#0_Worker-9] -
get:: configKeyCryptClassName: null
WARN 07-19 08:39:19.644 c.h.i.c.i.ClusterHeartbeatManager:67
[ached.thread-11] - [172.31.47.17]:5701 [dev] [5.1.1] Resetting
heartbeat timestamps because of huge system clock jump! Clock-Jump:
32220 ms, Heartbeat-Timeout: 60000 ms
DEBUG 07-19 08:39:49.687 o.a.o.u.c.CryptProvider:36 [Bean#0_Worker-1] -
get:: configKeyCryptClassName: null
DEBUG 07-19 08:40:56.404 o.a.o.u.c.CryptProvider:36 [Bean#0_Worker-3] -
get:: configKeyCryptClassName: null
DEBUG 07-19 08:41:24.903 o.a.o.u.c.CryptProvider:36 [Bean#0_Worker-8] -
get:: configKeyCryptClassName: null
Things start going wrong.
WARN 07-19 08:41:25.921 o.k.j.c.JsonRpcClient:270 [rbeatExec-e1-t0] -
Error sending heartbeat to server. Exception: Timeout of 10000
milliseconds waiting from response to request
{"id":6,"method":"ping","jsonrpc":"2.0","params":{"sessionId":"59473670-523a-435d-8fd3-acee604e5b61"}}
WARN 07-19 08:41:25.922 o.k.j.c.JsonRpcClient:287 [rbeatExec-e1-t0] -
Stopping heartbeat and closing client: failure during heartbeat mechanism
INFO 07-19 08:41:25.927 o.k.j.c.JsonRpcClientNettyWebSocket:275
[ntLoopGroup-2-1] - channel closed
DEBUG 07-19 08:41:25.927 o.a.o.c.r.KurentoHandler:167 [ntLoopGroup-2-1]
- JsonRpcWsClient disconnected from ws://127.0.0.1:8888/kurento because
Channel closed.
INFO 07-19 08:41:25.927 o.a.o.c.r.KurentoHandler:158 [ntLoopGroup-2-1]
- !!! Kurento disconnected
DEBUG 07-19 08:41:25.927 o.a.o.c.r.KurentoHandler:207 [ntLoopGroup-2-1]
- Client will be destroyed ...
WARN 07-19 08:41:25.928 o.k.j.c.JsonRpcClientNettyWebSocket:308
[ntLoopGroup-2-1] - Trying to close a JsonRpcClientNettyWebSocket with
channel == null
WARN 07-19 08:41:25.928 o.k.j.c.JsonRpcClientNettyWebSocket:308
[ntLoopGroup-2-1] - Trying to close a JsonRpcClientNettyWebSocket with
channel == null
WARN 07-19 08:41:25.928 o.k.j.c.JsonRpcClientNettyWebSocket:291
[ntLoopGroup-2-1] - Trying to close a JsonRpcClientNettyWebSocket with
group == null
DEBUG 07-19 08:41:25.928 o.a.o.c.r.KurentoHandler:209 [ntLoopGroup-2-1]
- .... Client is destroyed
INFO 07-19 08:41:25.936 o.a.o.c.r.KurentoHandler:158 [rbeatExec-e1-t0]
- !!! Kurento disconnected
ERROR 07-19 08:41:26.668 o.j.l.o.LocalOfficeProcessManager:217
[er-offprocmng-0] - Could not start the office process.
org.jodconverter.core.office.OfficeException: An error prevents us to
start a process with --accept
'socket,host=127.0.0.1,port=2002,tcpNoDelay=1;urp;StarOffice.ServiceManager'
at
org.jodconverter.local.office.LocalOfficeProcessManager.startProcessAndConnect(LocalOfficeProcessManager.java:417)
at
org.jodconverter.local.office.LocalOfficeProcessManager.lambda$start$1(LocalOfficeProcessManager.java:215)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.jodconverter.core.office.RetryTimeoutException:
org.jodconverter.local.office.OfficeConnectionException: Connection
failed: 'socket,host=127.0.0.1,port=2002,tcpNoDelay=1';
java.net.ConnectException: Connection refused (Connection refused)
at
org.jodconverter.core.office.AbstractRetryable.execute(AbstractRetryable.java:86)
at
org.jodconverter.core.office.AbstractRetryable.execute(AbstractRetryable.java:54)
at
org.jodconverter.local.office.LocalOfficeProcessManager.startProcessAndConnect(LocalOfficeProcessManager.java:405)
... 4 common frames omitted
Caused by: org.jodconverter.local.office.OfficeConnectionException:
Connection failed: 'socket,host=127.0.0.1,port=2002,tcpNoDelay=1';
java.net.ConnectException: Connection refused (Connection refused)
at
org.jodconverter.local.office.OfficeConnection.connect(OfficeConnection.java:188)
at
org.jodconverter.local.office.StartProcessAndConnectRetryable.attempt(StartProcessAndConnectRetryable.java:129)
at
org.jodconverter.core.office.AbstractRetryable.execute(AbstractRetryable.java:77)
... 6 common frames omitted
Caused by: com.sun.star.connection.NoConnectException:
java.net.ConnectException: Connection refused (Connection refused)
at
com.sun.star.lib.connections.socket.socketConnector.connect(socketConnector.java:144)
at com.sun.star.comp.connections.Connector.connect(Connector.java:119)
at
org.jodconverter.local.office.OfficeConnection.connect(OfficeConnection.java:114)
... 8 common frames omitted
INFO 07-19 08:41:26.669 o.j.l.o.LocalOfficeProcessManager:719
[er-offprocmng-0] - Process exited with code 0
WARN 07-19 08:41:26.861 c.h.s.i.o.i.InvocationMonitor:67
[onMonitorThread] - [172.31.47.17]:5701 [dev] [5.1.1]
MonitorInvocationsTask delayed 11422 ms
WARN 07-19 08:41:26.862 c.h.s.i.o.i.InvocationMonitor:67
[onMonitorThread] - [172.31.47.17]:5701 [dev] [5.1.1]
MonitorInvocationsTask delayed 172068 ms
WARN 07-19 08:41:26.862 c.h.s.i.o.i.InvocationMonitor:67
[onMonitorThread] - [172.31.47.17]:5701 [dev] [5.1.1]
BroadcastOperationControlTask delayed 170490 ms
WARN 07-19 08:41:26.919 o.j.l.o.LocalOfficeProcessManager:816
[er-offprocmng-0] - Could not delete profileDir; renamed it to
'/home/ubuntu/apache-openmeetings-6.3.0/temp/.jodconverter_socket_host-127.0.0.1_port-2002_tcpNoDelay-1.old.1658220086918'
java.nio.file.DirectoryNotEmptyException:
/home/ubuntu/apache-openmeetings-6.3.0/temp/.jodconverter_socket_host-127.0.0.1_port-2002_tcpNoDelay-1
at
java.base/sun.nio.fs.UnixFileSystemProvider.implDelete(UnixFileSystemProvider.java:247)
at
java.base/sun.nio.fs.AbstractFileSystemProvider.delete(AbstractFileSystemProvider.java:105)
at java.base/java.nio.file.Files.delete(Files.java:1142)
at
org.jodconverter.core.util.FileUtils.lambda$delete$0(FileUtils.java:180)
at
java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
at
java.base/java.util.stream.SortedOps$RefSortingSink.end(SortedOps.java:395)
at java.base/java.util.stream.Sink$ChainedReference.end(Sink.java:258)
at
java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:485)
at
java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
at
java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
at
java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
at
java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
at
java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
at org.jodconverter.core.util.FileUtils.delete(FileUtils.java:177)
at
org.jodconverter.local.office.LocalOfficeProcessManager.deleteInstanceProfileDir(LocalOfficeProcessManager.java:809)
at
org.jodconverter.local.office.LocalOfficeProcessManager.ensureProcessExited(LocalOfficeProcessManager.java:727)
at
org.jodconverter.local.office.LocalOfficeProcessManager.stopProcess(LocalOfficeProcessManager.java:480)
at
org.jodconverter.local.office.LocalOfficeProcessManager.lambda$stop$4(LocalOfficeProcessManager.java:318)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
DEBUG 07-19 08:41:28.288 o.a.o.u.c.CryptProvider:36 [Bean#0_Worker-2] -
get:: configKeyCryptClassName: null
DEBUG 07-19 08:41:32.283 o.a.o.c.r.KurentoHandler:147 [pool-1-thread-1]
- Reconnecting KMS
INFO 07-19 08:41:32.284 o.k.j.c.JsonRpcClientNettyWebSocket:191
[pool-1-thread-1] - Connecting native client
INFO 07-19 08:41:32.285 o.k.j.c.JsonRpcClientNettyWebSocket:220
[pool-1-thread-1] - Creating new NioEventLoopGroup
INFO 07-19 08:41:32.287 o.k.j.c.JsonRpcClientNettyWebSocket:234
[ntLoopGroup-3-1] - Initiating new Netty channel. Will create new
handler too!
INFO 07-19 08:41:32.298 o.a.o.c.r.KurentoHandler:177 [pool-1-thread-1]
- !!! Kurrento connected
At this point the console has recovered. But tomcat is dead.
My best guess is that the failure to find/start jodconverter causes
something to go into a tight loop. This then uses all the cpu resources
and causes other things to fail. I thought jodconverter was now built
into openmeetings.
Help! I am out of my depth here?
Roger
