Hello,
I just installed the 3.1.1 update, and now the Application is loading indefinitely after logging in (logging in works without problems. I looked into the logs and found this in cmdbuild.sys:
2019-10-04 10:24:25.192 [req:59289e] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$70555f19 - processed request, returned error for requestId = 59289e87440a44188zxp2al5
2019-10-04 10:24:25.193 [req:0e7f90] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$70555f19 - processed request, returned error for requestId = 0e7f90135138454215f3e4oo
2019-10-04 10:24:25.196 [req:f8ac1a] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$70555f19 - processed request, returned error for requestId = f8ac1ad70a274be3jmt1e7fj
2019-10-04 10:24:25.198 [req:2af231] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$70555f19 - processed request, returned error for requestId = 2af231e2bae54881107tztfz
2019-10-04 10:24:25.197 [req:4cc639] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$70555f19 - processed request, returned error for requestId = 4cc639b9d0034663xwi9p3sb
2019-10-04 10:24:25.214 [req:a9182c] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$70555f19 - processed request, returned error for requestId = a9182c22eb8146c7xpwg0r4y
2019-10-04 10:24:25.412 [req:b6defc] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$70555f19 - processed request, returned error for requestId = b6defc5f4f334282cdwp5548
2019-10-04 10:24:25.417 [req:9b2d48] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$70555f19 - processed request, returned error for requestId = 9b2d480fe0c24c7f8g08wcyj
2019-10-04 10:25:00.015 [job:sysmonServiceImpl_logSystemStatus_2dfhsjla3tcobsm3btyaza6yy03] WARN o.cmdbuild.sysmon.SysmonServiceImpl - CMO: WARNING: high cpu load, loadavg = 1.31, loadavg/cpu = 1.31
2019-10-04 10:25:00.048 [system] WARN o.c.r.impl.RequestContextServiceImpl - invoked getRequestContext(), but there is no request context set on this thread! generating sys request context = RequestContext{id=sys_org.cmdbuild.sysnoti_cn5y2vz957vq554zrtczpyox}
2019-10-04 10:25:00.049 [system] WARN o.c.r.impl.RequestContextServiceImpl - invoked getRequestContext(), but there is no request context set on this thread! generating sys request context = RequestContext{id=sys_org.cmdbuild.sysnoti_myyg6r3ep16lwz6uffjxluyf}
2019-10-04 10:26:00.014 [job:sysmonServiceImpl_logSystemStatus_2dfhsjla3tcobsm3btyaza6yy03] WARN o.cmdbuild.sysmon.SysmonServiceImpl - CMO: WARNING: high cpu load, loadavg = 1.29, loadavg/cpu = 1.29
Any ideas why this might be happening? Iâm return to the old version for now.
Hi, can you please attach the requests that go in error? Also what are the details of the hardware and software you are using to run CMDBuild?
Thank you for replying 
What do you mean by âattaching the requestâ? I get these errors as soon as the application loads when iâm logged in, I canât do anything else. In cmdbuild_req.log are the same errors I found in cmdbuild_sys.log.
Iâm running psql 9.6.15 and cmdbuild 3.1.1.
Itâs a virtual server with 4 cores and 4GB RAM.
Hi, i have the same problem with both installations (demo / empty) i can log in into CMDBuild normally but then i also only get the loading wheel. In my browser consolt i can see the following errors:
i also get those error entries in the log.
1 Like
Hi, can you please try deleting your browser cache and your browser cookies?
Hi, i just tried it again after clearing my browser cache. I also tried it with a fresh installed browser (firefox) but still no luck
1 Like
Hello, strangely it only worked while still using the old âsessionâ with cookies and the cache, when I tried it with freshly installed firefox it didnât work at all.
Hope this adds some clue.
I believe itâs about this:
org.springframework.security.authentication.InsufficientAuthenticationException: Full authentication is required to access this resource
I tried several installation and i can only see a bounch of these in tomcat/cmdbuild.log:
2019-10-07 05:50:19.247 [req:188eb3] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$c53f45a7 - processed request, returned error for requestId = 188eb3dtxmqlcwhhg0gojh1a
2019-10-07 05:50:22.227 [req:ufwj0y] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$c53f45a7 - processed request, returned error for requestId = ufwj0yg2y3r017x6w0vbg95f
2019-10-07 05:50:24.934 [req:8fkx0v] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$c53f45a7 - processed request, returned error for requestId = 8fkx0vbdxtsyy7yq2rg6fd41
2019-10-07 05:59:06.256 [req:v98h76] WARN o.c.w.f.RequestTrackingFilter$$EnhancerBySpringCGLIB$$c53f45a7 - processed request, returned error for requestId = v98h76379r94zojp8y741myc
Long shot here but i saw that in the new features the cookie management has been offloaded to tomcat, maybe there is some leftover of the previous code?
Giuseppe
I now set up a dev environment where I can properly test the update.
Upon further investigation I found that this is the main error:
âorg.springframework.security.authentication.InsufficientAuthenticationException: Full authentication is required to access this resourceâ
Can you please check in the cmdbuild.log file if there are any errors on the web apllication startup? Can you also attach here the log file?
Hello, I checked the cmdbuild.log file while restarting and there are no errors. There is still the error when loading the application as described in the main post and by @giuseppe.urso.
Here my log file cut off from when I started the update: cmdbuild.log (517.0 KB)
As per previous post, here is the second part of the log:
2019-10-07 07:12:49.603 [system] INFO o.s.s.web.DefaultSecurityFilterChain - Creating filter chain: OrRequestMatcher [requestMatchers=[Ant [pattern='/services/rest/v*/sessions/**'], Ant [pattern='/services/custom-login'], Ant [pattern='/services/custom-login/**']]], [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@45e7d7c, org.springframework.security.web.context.SecurityContextPersistenceFilter@3db9c7d3, org.springframework.security.web.header.HeaderWriterFilter@7bfbf16d, org.springframework.web.filter.CorsFilter@6efb54fc, org.cmdbuild.webapp.security.LenientSessionTokenFilter@59546def, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@634a369b, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@479ed306, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@32d0960f, org.springframework.security.web.session.SessionManagementFilter@15207154, org.springframework.security.web.access.ExceptionTranslationFilter@5d707ba4, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@42d53755]
2019-10-07 07:12:49.607 [system] INFO o.s.s.web.DefaultSecurityFilterChain - Creating filter chain: Ant [pattern='/services/**'], [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@f5a7d1c, org.springframework.security.web.context.SecurityContextPersistenceFilter@1e5ee4b2, org.springframework.security.web.header.HeaderWriterFilter@6d6a3f1c, org.springframework.web.filter.CorsFilter@18e17c, org.cmdbuild.webapp.security.SessionTokenFilter@8330b3a, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@4c59bdeb, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@70f7f9a3, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@fc7c06f, org.springframework.security.web.session.SessionManagementFilter@4e71b2c7, org.springframework.security.web.access.ExceptionTranslationFilter@3d6df70d, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@64bc79fa]
2019-10-07 07:12:49.630 [system] INFO o.s.s.web.DefaultSecurityFilterChain - Creating filter chain: org.springframework.security.web.util.matcher.AnyRequestMatcher@1, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@15b303c5, org.springframework.security.web.context.SecurityContextPersistenceFilter@5c69fa4e, org.springframework.security.web.header.HeaderWriterFilter@6c93950a, org.springframework.security.web.authentication.logout.LogoutFilter@41c922d8, org.cmdbuild.webapp.security.UiSessionTokenFilter@3ef47b7c, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@10249b2, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@71c9a75d, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@2195ac3c, org.springframework.security.web.session.SessionManagementFilter@488c32ae, org.springframework.security.web.access.ExceptionTranslationFilter@5201e6ef, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@5dd2bee]
2019-10-07 07:12:49.755 [system] INFO o.cmdbuild.minions.SystemServiceImpl - spring context is ready
2019-10-07 07:12:49.757 [sys:boot] INFO o.cmdbuild.minions.SystemServiceImpl - start system
2019-10-07 07:12:49.764 [system] INFO o.s.web.context.ContextLoader - Root WebApplicationContext: initialization completed in 18525 ms
2019-10-07 07:12:49.774 [sys:boot] INFO o.c.config.service.ConfigServiceImpl - init config beans
2019-10-07 07:12:49.908 [sys:boot] INFO o.cmdbuild.minions.MinionServiceImpl - loading 14 system services
2019-10-07 07:12:49.916 [sys:boot] INFO o.c.c.s.ConfigChangeNotifierService - init 16 config change listeners
2019-10-07 07:12:49.926 [sys:boot] INFO o.c.config.service.ConfigServiceImpl - load config from files
2019-10-07 07:12:49.952 [sys:boot] WARN o.c.c.s.FilesystemConfigRepositoryImpl - config files backup error
java.io.FileNotFoundException: /opt/tomcat/conf/ROOT/backup/config_files_2019-10-07_07-12-49/database.conf (No such file or directory)
at java.io.FileOutputStream.open0(Native Method) ~[na:1.8.0_222]
at java.io.FileOutputStream.open(FileOutputStream.java:270) ~[na:1.8.0_222]
at java.io.FileOutputStream.<init>(FileOutputStream.java:213) ~[na:1.8.0_222]
at com.google.common.io.Files$FileByteSink.openStream(Files.java:214) ~[guava-23.0.jar:na]
at com.google.common.io.Files$FileByteSink.openStream(Files.java:202) ~[guava-23.0.jar:na]
at com.google.common.io.ByteSource.copyTo(ByteSource.java:268) ~[guava-23.0.jar:na]
at com.google.common.io.Files.copy(Files.java:325) ~[guava-23.0.jar:na]
at org.cmdbuild.config.service.FilesystemConfigRepositoryImpl.lambda$backupConfigFiles$4(FilesystemConfigRepositoryImpl.java:130) [cmdbuild-core-config-3-SNAPSHOT.jar:na]
at org.cmdbuild.utils.lang.LambdaExceptionUtils.lambda$rethrowConsumer$0(LambdaExceptionUtils.java:56) ~[cmdbuild-utils-lang-3-SNAPSHOT.jar:na]
at java.util.ArrayList.forEach(ArrayList.java:1257) ~[na:1.8.0_222]
at org.cmdbuild.config.service.FilesystemConfigRepositoryImpl.backupConfigFiles(FilesystemConfigRepositoryImpl.java:128) [cmdbuild-core-config-3-SNAPSHOT.jar:na]
at org.cmdbuild.config.service.FilesystemConfigRepositoryImpl.getConfigEntries(FilesystemConfigRepositoryImpl.java:80) [cmdbuild-core-config-3-SNAPSHOT.jar:na]
at org.cmdbuild.config.service.ConfigRepositoryFacadeImpl.loadConfigFromFiles(ConfigRepositoryFacadeImpl.java:48) [cmdbuild-core-config-3-SNAPSHOT.jar:na]
at org.cmdbuild.config.service.ConfigServiceImpl$2.handleSystemLoadingConfigFilesEvent(ConfigServiceImpl.java:111) [cmdbuild-core-config-3-SNAPSHOT.jar:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_222]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_222]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_222]
at com.google.common.eventbus.Subscriber.invokeSubscriberMethod(Subscriber.java:91) [guava-23.0.jar:na]
at com.google.common.eventbus.Subscriber$SynchronizedSubscriber.invokeSubscriberMethod(Subscriber.java:150) [guava-23.0.jar:na]
at com.google.common.eventbus.Subscriber$1.run(Subscriber.java:76) [guava-23.0.jar:na]
at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:399) [guava-23.0.jar:na]
at com.google.common.eventbus.Subscriber.dispatchEvent(Subscriber.java:71) [guava-23.0.jar:na]
at com.google.common.eventbus.Dispatcher$PerThreadQueuedDispatcher.dispatch(Dispatcher.java:116) [guava-23.0.jar:na]
at com.google.common.eventbus.EventBus.post(EventBus.java:217) [guava-23.0.jar:na]
at java.util.Optional.ifPresent(Optional.java:159) ~[na:1.8.0_222]
at org.cmdbuild.minions.SystemServiceImpl.setSystemStatus(SystemServiceImpl.java:239) ~[cmdbuild-core-all-3-SNAPSHOT.jar:na]
at org.cmdbuild.minions.SystemServiceImpl.runNextStep(SystemServiceImpl.java:207) ~[cmdbuild-core-all-3-SNAPSHOT.jar:na]
at org.cmdbuild.minions.SystemServiceImpl.runNextStep(SystemServiceImpl.java:208) ~[cmdbuild-core-all-3-SNAPSHOT.jar:na]
at org.cmdbuild.minions.SystemServiceImpl.lambda$handleContextRefresh$0(SystemServiceImpl.java:138) ~[cmdbuild-core-all-3-SNAPSHOT.jar:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_222]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) ~[na:1.8.0_222]
2019-10-07 07:12:50.037 [sys:boot] INFO o.c.d.d.ConfigurableDataSourceImpl - postgres driver = org.postgresql.Driver
2019-10-07 07:12:50.037 [sys:boot] INFO o.c.d.d.ConfigurableDataSourceImpl - postgres driver version = PostgreSQL JDBC Driver 42.2.5
2019-10-07 07:12:50.038 [sys:boot] INFO o.c.d.d.ConfigurableDataSourceImpl - configure datasource with url = jdbc:postgresql://10.0.0.36:5432/cmdbuild with user = cmdbuild
2019-10-07 07:12:50.141 [sys:boot] INFO o.c.d.d.ConfigurableDataSourceImpl - postgres server version = 9.6.10
2019-10-07 07:12:50.420 [sys:boot] INFO o.cmdbuild.minions.SystemServiceImpl -
system is CHECKING_DATABASE
2019-10-07 07:12:50.421 [sys:boot] INFO o.cmdbuild.minions.SystemServiceImpl - check patch manager
2019-10-07 07:12:50.438 [sys:boot] INFO o.cmdbuild.minions.SystemServiceImpl -
system is LOADING_CONFIG
2019-10-07 07:12:50.438 [sys:boot] INFO o.c.config.service.ConfigServiceImpl - load config from db
2019-10-07 07:12:50.462 [sys:boot] INFO o.cmdbuild.minions.SystemServiceImpl -
system is STARTING_SERVICES
2019-10-07 07:12:50.462 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method clusterServiceImpl#startIfEnabled
2019-10-07 07:12:50.462 [sys:boot] INFO o.c.cluster.ClusterServiceImpl - clustering is disabled
2019-10-07 07:12:50.462 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method platformServiceImpl#fixPermissions
2019-10-07 07:12:50.463 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method rawDataSource#checkAndConfigureSqlLogger
2019-10-07 07:12:50.463 [sys:boot] INFO o.c.d.d.ConfigurableDataSourceImpl - enable sql logger
2019-10-07 07:12:50.469 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method multitenantServiceImpl#check
2019-10-07 07:12:50.470 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method jasperReportContextServiceImpl#loadJasperReportsContext
2019-10-07 07:12:51.647 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method sharkWebserviceClientImpl#startSharkWsClient
2019-10-07 07:12:51.649 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method planServiceDelegateSupplierImpl#loadConfig
2019-10-07 07:12:51.650 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method workflowServiceDelegates#loadConfig
2019-10-07 07:12:51.652 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method databaseStatusServiceImpl#init
2019-10-07 07:12:51.661 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method easyuploadLoaderService#checkUploadsFolderAndLoadContent
2019-10-07 07:12:51.662 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method easyuploadFtpService#startFtpServerIfEnabled
2019-10-07 07:12:51.663 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method logbackConfigServiceImpl#init
2019-10-07 07:12:51.691 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method sysmonServiceImpl#logSystemInfo
2019-10-07 07:12:51.692 [sys:boot] INFO o.cmdbuild.sysmon.SysmonServiceImpl - default charset = UTF-8
2019-10-07 07:12:51.692 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method schedulerServiceImpl#startup
2019-10-07 07:12:51.692 [sys:boot] INFO o.c.s.quartz.SchedulerServiceImpl - start quartz service
2019-10-07 07:12:51.692 [sys:boot] INFO o.c.s.quartz.SchedulerServiceImpl - preparing quartz scheduler with job sources = core,jobs
2019-10-07 07:12:51.755 [sys:boot] INFO org.quartz.impl.StdSchedulerFactory - Using default implementation for ThreadExecutor
2019-10-07 07:12:51.774 [sys:boot] INFO o.quartz.core.SchedulerSignalerImpl - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2019-10-07 07:12:51.775 [sys:boot] INFO org.quartz.core.QuartzScheduler - Quartz Scheduler v.2.2.2 created.
2019-10-07 07:12:51.777 [sys:boot] INFO o.q.impl.jdbcjobstore.JobStoreTX - Using db table-based data access locking (synchronization).
2019-10-07 07:12:51.779 [sys:boot] INFO o.q.impl.jdbcjobstore.JobStoreTX - JobStoreTX initialized.
2019-10-07 07:12:51.781 [sys:boot] INFO org.quartz.core.QuartzScheduler - Scheduler meta-data: Quartz Scheduler (v2.2.2) 'CMDBuildScheduler' with instanceId 'cmdbuild_cmdbuild-test_3555'
Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
NOT STARTED.
Currently in standby mode.
Number of jobs executed: 0
Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 5 threads.
Using job-store 'org.quartz.impl.jdbcjobstore.JobStoreTX' - which supports persistence. and is clustered.
2019-10-07 07:12:51.781 [sys:boot] INFO org.quartz.impl.StdSchedulerFactory - Quartz scheduler 'CMDBuildScheduler' initialized from an externally provided properties instance.
2019-10-07 07:12:51.781 [sys:boot] INFO org.quartz.impl.StdSchedulerFactory - Quartz scheduler version: 2.2.2
2019-10-07 07:12:51.783 [sys:boot] INFO org.quartz.core.QuartzScheduler - JobFactory set to: org.cmdbuild.scheduler.quartz.SchedulerServiceImpl$MyJobFactory@22847ad3
2019-10-07 07:12:51.812 [sys:boot] INFO o.c.s.quartz.SchedulerServiceImpl - check status of 10 configured jobs
2019-10-07 07:12:51.863 [sys:boot] INFO o.c.s.quartz.SchedulerServiceImpl - start scheduler
2019-10-07 07:12:51.868 [sys:boot] INFO o.q.impl.jdbcjobstore.JobStoreTX - ClusterManager: detected 1 failed or restarted instances.
2019-10-07 07:12:51.869 [sys:boot] INFO o.q.impl.jdbcjobstore.JobStoreTX - ClusterManager: Scanning for instance "cmdbuild_cmdbuild-test_1720"'s failed in-progress jobs.
2019-10-07 07:12:51.884 [sys:boot] INFO org.quartz.core.QuartzScheduler - Scheduler CMDBuildScheduler_$_cmdbuild_cmdbuild-test_3555 started.
2019-10-07 07:12:51.886 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method bimserverClientServiceImpl#init
2019-10-07 07:12:51.887 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method databaseHousekeepingService#runDatabaseHousekeepingAtStartup
2019-10-07 07:12:51.887 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method postgresDateServiceImpl#printInfo
2019-10-07 07:12:51.891 [system] INFO o.q.impl.jdbcjobstore.JobStoreTX - Handling 1 trigger(s) that missed their scheduled fire-time.
2019-10-07 07:12:51.892 [system] WARN o.c.r.impl.RequestContextServiceImpl - invoked getRequestContext(), but there is no request context set on this thread! generating sys request context = RequestContext{id=sys_QuartzScheduler_CMDB_2u8jjq9w6ac62yebz91l556s}
2019-10-07 07:12:51.892 [sys:boot] INFO o.c.d.p.PostgresDateServiceImpl - postgres db timezone = America/New_York
2019-10-07 07:12:51.895 [sys:boot] INFO o.c.d.p.PostgresDateServiceImpl - postgres db timezone offset = -04:00
2019-10-07 07:12:51.896 [sys:boot] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - run PostStartup method ws3Loader#startWs3
2019-10-07 07:12:51.896 [sys:boot] INFO org.cmdbuild.webapp.Ws3Loader - start ws3
2019-10-07 07:12:52.051 [sys:boot] INFO org.reflections.Reflections - Reflections took 130 ms to scan 1 urls, producing 8 keys and 207 values
2019-10-07 07:12:52.187 [sys:boot] INFO org.cmdbuild.webapp.Ws3Loader - ws3 ready
2019-10-07 07:12:52.190 [sys:boot] INFO o.cmdbuild.minions.SystemServiceImpl -
___ __ __ ___ ___ _ _ _
/ __| \/ | \| _ )_ _(_) |__| |
| (__| |\/| | |) | _ \ || | | / _` |
\___|_| |_|___/|___/\_,_|_|_\__,_|
v3.1.1 READY
BIM Bimserver client disabled
BIM Service disabled
Clustering disabled
Cmis DMS client disabled
DMS Service disabled
Email Queue disabled
Ftp Service disabled
GIS GeoServer client disabled
GIS Service disabled
Multitenant disabled
Postgres DMS Service disabled
Quartz Scheduler (core) * ready
Scheduled Jobs disabled
Workflow Engine * ready
running source code rev 746fce5/stable/3.1.1 (2019-09-25T08:48:45Z)
startup (uptime) 34.329s
2019-10-07 07:12:52.191 [sys:boot] INFO o.c.w.f.BootCheckFilter$$EnhancerBySpringCGLIB$$de41c86 - system running, disable boot services
Thank you,
Giuseppe
Unfortunately the length of the log exceeds the maximum length for a post on this forum.
I cannot post links either, so itâs gonna be in two halves. Sorry about that.
[root@cmdbuild-test logs]# cat ROOT.log
2019-10-07 07:12:31.237 [system] INFO o.c.w.LogbackConfigurationContextListener - logger ready
2019-10-07 07:12:31.239 [system] INFO o.s.web.context.ContextLoader - Root WebApplicationContext: initialization started
2019-10-07 07:12:31.357 [system] INFO o.s.w.c.s.XmlWebApplicationContext - Refreshing Root WebApplicationContext: startup date [Mon Oct 07 07:12:31 EDT 2019]; root of context hierarchy
2019-10-07 07:12:31.410 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/cmdbuild/web-application-context.xml]
2019-10-07 07:12:31.565 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/cmdbuild/core-application-context.xml]
2019-10-07 07:12:32.379 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/cmdbuild/rest/rest_v2.xml]
2019-10-07 07:12:32.390 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [META-INF/cxf/cxf.xml]
2019-10-07 07:12:32.442 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/cmdbuild/rest/rest_v3.xml]
2019-10-07 07:12:32.450 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [META-INF/cxf/cxf.xml]
2019-10-07 07:12:32.458 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/cmdbuild/soap/soapws.xml]
2019-10-07 07:12:32.464 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [META-INF/cxf/cxf.xml]
2019-10-07 07:12:32.470 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/cmdbuild/soap/soapws-r1.xml]
2019-10-07 07:12:32.498 [system] INFO o.s.b.f.xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/cmdbuild/soap/soapws-r2.xml]
2019-10-07 07:12:34.157 [system] INFO o.s.b.f.a.AutowiredAnnotationBeanPostProcessor - JSR-330 'javax.inject.Inject' annotation found and supported for autowiring
2019-10-07 07:12:34.348 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration' of type [class org.springframework.security.config.annotation.configuration.ObjectPostProcessorConfiguration$$EnhancerBySpringCGLIB$$4f94e7d1] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.640 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'objectPostProcessor' of type [class org.springframework.security.config.annotation.configuration.AutowireBeanFactoryObjectPostProcessor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.651 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler@1378bbf3' of type [class org.springframework.security.access.expression.method.DefaultMethodSecurityExpressionHandler] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.677 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration' of type [class org.springframework.security.config.annotation.method.configuration.GlobalMethodSecurityConfiguration$$EnhancerBySpringCGLIB$$74698a83] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.786 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'methodSecurityMetadataSource' of type [class org.springframework.security.access.method.DelegatingMethodSecurityMetadataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.828 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'configBeanRepositoryImpl' of type [class org.cmdbuild.config.service.ConfigBeanRepositoryImpl] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.839 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'configListenerBeansRepositoryImpl' of type [class org.cmdbuild.config.service.ConfigListenerBeansRepositoryImpl] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.864 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'minionBeanRepository' of type [class org.cmdbuild.minions.MinionBeanRepository] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.879 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'systemEventServiceImpl' of type [class org.cmdbuild.system.SystemEventServiceImpl] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.903 [system] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'annotatedMethodJobService' of type [class org.cmdbuild.scheduler.annotatedmethodjobs.AnnotatedMethodJobService] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-10-07 07:12:34.986 [system] INFO o.c.w.s.WebappDirectoryServiceImpl - cmdbuild webapp dir = /opt/tomcat/webapps/ROOT
2019-10-07 07:12:34.986 [system] INFO o.c.w.s.WebappDirectoryServiceImpl - cmdbuild config dir = /opt/tomcat/conf/ROOT
2019-10-07 07:12:34.986 [system] INFO o.c.w.s.WebappDirectoryServiceImpl - container dir = /opt/tomcat
2019-10-07 07:12:35.091 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = clusterServiceImpl ( org.cmdbuild.cluster.ClusterServiceImpl )
2019-10-07 07:12:35.118 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method clusterServiceImpl#stopSafe for PreShutdown hook
2019-10-07 07:12:35.129 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method clusterServiceImpl#startIfEnabled for PostStartup hook
2019-10-07 07:12:35.169 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method platformServiceImpl#fixPermissions for PostStartup hook
2019-10-07 07:12:35.282 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method rawDataSource#checkAndConfigureSqlLogger for PostStartup hook
2019-10-07 07:12:35.991 [system] INFO o.c.d.orm.services.CardMapperLoader - scanClassesForHandlers BEGIN
2019-10-07 07:12:36.617 [system] INFO o.c.d.orm.services.CardMapperLoader - scanClassesForHandlers END
2019-10-07 07:12:37.108 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = multitenantServiceImpl ( org.cmdbuild.auth.multitenant.MultitenantServiceImpl )
2019-10-07 07:12:37.152 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method multitenantServiceImpl#check for PostStartup hook
2019-10-07 07:12:37.496 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method jasperReportContextServiceImpl#loadJasperReportsContext for PostStartup hook
2019-10-07 07:12:38.489 [system] INFO o.c.a.s.dao.SessionRepositoryImpl - init
2019-10-07 07:12:38.514 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = SessionRepositoryImpl (sessionRepositoryImpl) method = cleanupSessionStore trigger = '0 0 * * * ?'
2019-10-07 07:12:38.636 [system] INFO org.cmdbuild.lock.LockRepositoryImpl - init
2019-10-07 07:12:38.655 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = LockRepositoryImpl (lockRepositoryImpl) method = cleanupLockTable trigger = '0 10 * * * ?'
2019-10-07 07:12:38.864 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method sharkWebserviceClientImpl#startSharkWsClient for PostStartup hook
2019-10-07 07:12:39.106 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method planServiceDelegateSupplierImpl#loadConfig for PostStartup hook
2019-10-07 07:12:39.510 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = cmisDmsProviderService ( org.cmdbuild.dms.cmis.CmisDmsProviderService )
2019-10-07 07:12:39.573 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = pgDmsProviderServiceImpl ( org.cmdbuild.dms.dao.PgDmsProviderServiceImpl )
2019-10-07 07:12:39.596 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = dmsServiceImpl ( org.cmdbuild.dms.core.DmsServiceImpl )
2019-10-07 07:12:40.413 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method workflowServiceDelegates#loadConfig for PostStartup hook
2019-10-07 07:12:40.433 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = workflowServiceFacadeImpl ( org.cmdbuild.workflow.core.WorkflowServiceFacadeImpl )
2019-10-07 07:12:40.651 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = emailQueueServiceImpl ( org.cmdbuild.email.queue.EmailQueueServiceImpl )
2019-10-07 07:12:40.660 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = EmailQueueServiceImpl (emailQueueServiceImpl) method = processEmailQueue trigger = '0 */10 * * * ?'
2019-10-07 07:12:41.592 [system] INFO o.c.d.config.inner.PatchServiceImpl - init
2019-10-07 07:12:41.635 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method databaseStatusServiceImpl#init for PostStartup hook
2019-10-07 07:12:41.757 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = geoserverServiceImpl ( org.cmdbuild.gis.geoserver.GeoserverServiceImpl )
2019-10-07 07:12:41.771 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = gisService ( org.cmdbuild.gis.GisServiceImpl )
2019-10-07 07:12:41.872 [system] INFO o.cmdbuild.minions.SystemServiceImpl - received application context PostConstruct event
2019-10-07 07:12:41.911 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = ConfigBackupService (configBackupService) method = backupConfig trigger = '0 0 04 * * ?'
2019-10-07 07:12:42.091 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = EtlDataRepositoryImpl (etlDataRepositoryImpl) method = processedDataCleanup trigger = '0 0 04 * * ?'
2019-10-07 07:12:42.237 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = jobServiceImpl ( org.cmdbuild.jobs.JobServiceImpl )
2019-10-07 07:12:42.472 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method easyuploadLoaderService#checkUploadsFolderAndLoadContent for PostStartup hook
2019-10-07 07:12:42.472 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = EasyuploadLoaderService (easyuploadLoaderService) method = checkUploadsFolderAndLoadContent trigger = '*/10 * * * * ?'
2019-10-07 07:12:42.517 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = easyuploadFtpService ( org.cmdbuild.easyupload.ftp.EasyuploadFtpService )
2019-10-07 07:12:42.526 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method easyuploadFtpService#startFtpServerIfEnabled for PostStartup hook
2019-10-07 07:12:42.526 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method easyuploadFtpService#stopSafe for PreShutdown hook
2019-10-07 07:12:42.587 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method logbackConfigServiceImpl#init for PostStartup hook
2019-10-07 07:12:42.621 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method sysmonServiceImpl#logSystemInfo for PostStartup hook
2019-10-07 07:12:42.621 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = SysmonServiceImpl (sysmonServiceImpl) method = logSystemStatus trigger = '0 * * * * ?'
2019-10-07 07:12:42.655 [system] INFO o.c.l.ErrorOrWarningLogbackAppenderService - init
2019-10-07 07:12:42.678 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = TempServiceImpl (tempServiceImpl) method = removeExpiredRecords trigger = '0 */10 * * * ?'
2019-10-07 07:12:42.679 [system] WARN o.c.r.impl.RequestContextServiceImpl - invoked getRequestContext(), but there is no request context set on this thread! generating sys request context = RequestContext{id=sys_localhost-startStop-_dgs2b7dyefbzr0wp5p01nren}
2019-10-07 07:12:42.718 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = RequestTrackingServiceImpl (requestTrackingServiceImpl) method = doCleanupRequestTable trigger = '0 0 * * * ?'
2019-10-07 07:12:42.805 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = schedulerServiceImpl ( org.cmdbuild.scheduler.quartz.SchedulerServiceImpl )
2019-10-07 07:12:42.851 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method schedulerServiceImpl#stopService for PreShutdown hook
2019-10-07 07:12:42.851 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method schedulerServiceImpl#startup for PostStartup hook
2019-10-07 07:12:42.981 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = bimserverClientServiceImpl ( org.cmdbuild.bim.bimserverclient.BimserverClientServiceImpl )
2019-10-07 07:12:43.020 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method bimserverClientServiceImpl#init for PostStartup hook
2019-10-07 07:12:43.020 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method bimserverClientServiceImpl#cleanup for PreShutdown hook
2019-10-07 07:12:43.024 [system] INFO o.c.minions.MinionAnnotationHandler - register minion bean = bimServiceImpl ( org.cmdbuild.bim.BimServiceImpl )
2019-10-07 07:12:43.121 [system] INFO o.cmdbuild.webapp.log.LogServiceImpl - init
2019-10-07 07:12:43.898 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method databaseHousekeepingService#runDatabaseHousekeepingAtStartup for PostStartup hook
2019-10-07 07:12:43.906 [system] INFO o.c.s.a.ScheduledJobsAnnotationHandler - processing scheduled job from annotated method, bean = DatabaseHousekeepingService (databaseHousekeepingService) method = runDatabaseHousekeepingJob trigger = '0 0 4 * * ?'
2019-10-07 07:12:43.973 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method postgresDateServiceImpl#printInfo for PostStartup hook
2019-10-07 07:12:44.156 [system] INFO o.c.m.LifecycleBeanMethodAnnotationHandler - register method ws3Loader#startWs3 for PostStartup hook
2019-10-07 07:12:44.369 [system] INFO o.c.webapp.plus.TomcatPlusHelperImpl - unable to load tomcat plus delegate, tomcat plus is not available
2019-10-07 07:12:45.906 [system] INFO org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be /v2
2019-10-07 07:12:47.458 [system] INFO org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be /v3
2019-10-07 07:12:47.585 [system] INFO o.a.c.w.s.f.ReflectionServiceFactoryBean - Creating Service {http://soap.services.cmdbuild.org}WebservicesImplService from class org.cmdbuild.services.soap.Webservices
2019-10-07 07:12:48.545 [system] INFO org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be /Webservices
2019-10-07 07:12:48.663 [system] INFO o.a.c.w.s.f.ReflectionServiceFactoryBean - Creating Service {http://soap.services.cmdbuild.org}PrivateImplService from class org.cmdbuild.services.soap.Private
2019-10-07 07:12:49.078 [system] INFO org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be /Private
2019-10-07 07:12:49.327 [system] INFO o.s.s.web.DefaultSecurityFilterChain - Creating filter chain: Ant [pattern='/services/rest/v*/boot/status', GET], []
2019-10-07 07:12:49.327 [system] INFO o.s.s.web.DefaultSecurityFilterChain - Creating filter chain: Ant [pattern='/services/rest/v*/boot/status/', GET], []
2019-10-07 07:12:49.576 [system] INFO o.s.s.web.DefaultSecurityFilterChain - Creating filter chain: Ant [pattern='/services/rest/v*/boot/**'], [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@1462b14f, org.springframework.security.web.context.SecurityContextPersistenceFilter@41cca6a5, org.springframework.security.web.header.HeaderWriterFilter@36af6d82, org.springframework.web.filter.CorsFilter@1354c3fd, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@4b4c0c66, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@7e5c80da, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@36045f9e, org.springframework.security.web.session.SessionManagementFilter@86b667f, org.springframework.security.web.access.ExceptionTranslationFilter@5bd0d4e9, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@62eabd2f]
The remaining of the log in my following post.
By any chance do you have multiple instances of CMDBuild on the same server? If yes when switching between instances of different versions make sure you delete the cookies, more in specific the CMDBuild-Authorization cookies:
Hi, I used an incognito window as well, the problem persists the same way.
Checking the cookies anyway I see I be maybe missing the CMDBUILD-Authorization, which instead i see on the other instance of 3.1 (see attachment)
The 3.1.1:
This is instead the 3.1
Thanks,
Giuseppe
Sorry but i cannot edit my previous post.
I found also âWebSocket connection to âws://10.0.0.35:8080/services/websocket/v1/mainâ failed: HTTP Authentication failed; no valid credentials availableâ
Giuseppe
Are you using âhttpsâ or âhttpâ? Also what browser version are you using?
Hi, Iâm hitting directly tomcat on port 8080 so no ssl.
Iâm using Chrome Version 77.0.3865.90 (Official Build) (64-bit).
But as I said, 3.1 does work in the same setup.
I can attach my install script.
Tx
Giuseppe
And are you using the standard CMDBuild authentication system or are you using LDAP or any other auth methods?
Hi, Iâm using standard CMDBuild auth, just fresh installed with empty database.
Thanks,
Giuseppe