LPS:Espis

Z HelpDesk

ESPIS

Aplikace musí běžet pod uživatelem espis. Pomocí skriptu v init.d se pustí pod uživatelem espis. Když se zapínají postupně musím být pod uživatelem espis.

ssh root@espis
/etc/init.d/icz stop
/etc/init.d/icz start

Počkat cca 2 min a vyzkoušet. Pro provoz musí fungovat oracle databaze.

U spisovky běží několik tomcatů nevím proč, ale dá se to postartovat ručně pokud nefunguje skript.

/opt/icz/produkce/sprs/bin/opt.sh start
/opt/icz/produkce/espis_ws/bin/opt.sh start
/opt/icz/produkce/espis/bin/opt.sh start
/opt/icz/skolici/espis_dfc/bin/opt.sh start
/opt/icz/skolici/espis/bin/opt.sh start

Espis chyba liquibase-lock

Symptomy

Spisova sluzba nemuze nastartovat, pristup na adresu https://espis.zcu.cz/ konci zobrazenim chyby:

HTTP Status 404 - /prod/xervlet/sps
type Status report
message /prod/xervlet/sps
description The requested resource is not available.
Apache Tomcat/8.0.32

V logu spisove sluzby je toto

2019-08-19 07:49:51,847 INFO  LiquibaseLogger - liquibase Could not set remarks reporting on OracleDatabase: com.sun.proxy.$Proxy26.setRemarksReporting(boolean)
2019-08-19 07:49:51,927 INFO  LiquibaseLogger - liquibase Could not set check compatibility mode on OracleDatabase, assuming not running in any sort of compatibility mode: Cannot read from v$parameter: ORA-00942: table or view does not exist
2019-08-19 07:49:52,108 INFO  LiquibaseLogger - liquibase Waiting for changelog lock....
2019-08-19 07:50:02,116 INFO  LiquibaseLogger - liquibase Waiting for changelog lock....
2019-08-19 07:50:12,120 INFO  LiquibaseLogger - liquibase Waiting for changelog lock....
.
. 
.
2019-08-19 07:50:22,126 INFO  LiquibaseLogger - liquibase Waiting for changelog lock....
2019-08-19 07:50:32,130 INFO  LiquibaseLogger - liquibase Waiting for changelog lock....
2019-08-19 07:54:42,259 INFO  LiquibaseLogger - liquibase Waiting for changelog lock....
2019-08-19 07:54:52,275 WARN  org.springframework.web.context.support.XmlWebApplicationContext - Exception encountered during context initialization - cancelling refresh attempt: 
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'espisLiquibase' defined in class path resource [beans-espis.xml]: Invocation of init method failed; nested exception is 
liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by 147.228.52.43 (147.228.52.43) since 8/17/19 4:30 AM
2019-08-19 07:54:52,281 ERROR org.springframework.web.context.ContextLoader - Context initialization failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'espisLiquibase' defined in class path resource [beans-espis.xml]: Invocation of init method failed; nested exception is 
liquibase.exception.LockException: Could not acquire change log lock.  Currently locked by 147.228.52.43 (147.228.52.43) since 8/17/19 4:30 AM
       at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1628)
       at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:555)
       at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
       at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
       at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
       at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
       at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)....

Reseni

Z duvodu potreby rychleho reseni situace s ohledem na informace nalezene Sekym na StackOverflow: https://stackoverflow.com/questions/15528795/liquibase-lock-reasons jsme provedli zasahy primo v Oracle DB espis:

1) Zazalohovani jedineho radku v tabulce ESPIS.DATABASECHANGELOGLOCK

Insert into DATABASECHANGELOGLOCK
  (ID, LOCKED, LOCKGRANTED, LOCKEDBY)
Values
  (1, 1, TO_TIMESTAMP('17/08/2019 4:30:44,164000','DD/MM/YYYY fmHH24fm:MI:SS,FF'), '147.228.52.43 (147.228.52.43)');
--COMMIT;

2) Kontrola zda nefiguruje tabulka v referencnich vazbach a zda na ni nejsou triggery. Nic takoveho jsem nenalezel.

3) Smazani radku + commit;

Nasledne po restartu aplikace espis bez problemu nastartovala.

V logu je pak toto

2019-08-19 10:58:14 INFO  LiquibaseLogger:43 - liquibase Could not set remarks reporting on OracleDatabase: com.sun.proxy.$Proxy26.setRemarksReporting(boolean)
2019-08-19 10:58:14 INFO  LiquibaseLogger:43 - liquibase Successfully acquired change log lock
2019-08-19 10:58:15 INFO  LiquibaseLogger:43 - liquibase Reading from ESPIS.DATABASECHANGELOG
2019-08-19 10:58:15 INFO  LiquibaseLogger:43 - liquibase Custom SQL executed
2019-08-19 10:58:15 INFO  LiquibaseLogger:43 - liquibase ChangeSet setup.xml::NLS_LENGTH_SEMANTICS::JosefB ran successfully in 3ms
2019-08-19 10:58:15 INFO  LiquibaseLogger:43 - liquibase Successfully released change log lock
Espis usermanager add user: stag
Espis usermanager add user: api
Espis usermanager add user: scan        
.
.
.

Strucny vyklad

Liquibase je nejake ORM a pokud skonci jeho chod nejak nestandardne, zrejme neuklidi zaznam v te tabulce definujici nejaky zamek. Pri startu pak existence tohoto zamku zablokuje start. Je zajimave, ze zamek mel u sebe timestamp na 04:30 coz podle nastaveni CRONa na serveru eris je okamzik, kdy dochazi k restartu espis. Tedy sestrelil to dnesni planovany bezny rani restart???

Poznamky

1) INFO v logu: liquibase Could not set check compatibility mode on OracleDatabase, assuming not running in any sort of compatibility mode: Cannot read from v$parameter: ORA-00942: table or view does not exist

Lze resit pridelenim prav public na na V$parameter. Warning zmizi, nicmene neni to koncepcni reseni. Uzivatel, ktery se o select pokousi ma mit prislusna opravneni --> ICZ Ovsem warning je irelevantni k vyse uvedene chybe, nesouvisi s ni, pri minulych uspesnych startech espis nebo testovai espis byl rovnez v logu a aplikace pritom zjevne nastartovaly.

2) INFO v logu: Could not set remarks reporting on OracleDatabase: com.sun.proxy.$Proxy26.setRemarksReporting(boolean)

To same, nesouvisi zjevne s resenym problemem, funguje i presto.

3) tomcat zda se bezi (na portu 8080 lze overit). nicmene ajp hlasi nejake problemy (prvni vyskyt)

[Thu Aug 29 22:42:08.008201 2019] [proxy_ajp:error] [pid 4020:tid 140271928919808] [client 147.228.54.200:54412] AH00992: ajp_read_header: ajp_ilink_receive failed, referer: https://espis.zcu.cz/prod/xervlet/sps/selectFM
[Thu Aug 29 22:42:08.008222 2019] [proxy_ajp:error] [pid 4020:tid 140271928919808] (70007)The timeout specified has expired: [client 147.228.54.200:54412] AH00893: dialog to (null) (*) failed, referer: https://espis.zcu.cz/prod/xervlet/sps/selectFM

zaroven jdou videt tyto hlasky, coz by ale mohl byt zpusobeno cekamnim na ajp/tomcat

[Fri Aug 30 16:01:40.827070 2019] [webauth:error] [pid 9396:tid 140430188406528] mod_webauth: handle_id_token: id token too old
  • podle posledni zpravy se jim nezda neco v db a rekli standovi, at db votoci
  • v pondeli uz espis bezel, nic vic pry nedelali. svadi to na databazi. kdyz nastane podobny stav/zpomaleni odezvy, mame se ozvat, chteli by vedet, co v te db vyzere prostredky (jako konkretne sql)

@paja: jak tak koukám tak to s webkdc moc nesouvisí. Zdá se, že webauth si moc nerozumí s tím jak se handluje s URL a také jak to uživatelé používají (mají celý den otevřené okno). Zásadní problém by to být neměl. Problém s klíči mezi webkdc a mod_webauth se tam také nevyskytoval. Pokud by server měl špatný čas mohlo by se to chovat takto. Jinak už moc nevím.

Odkazy

kontakt

  • icz 222 271 560