Hi Olivier,
After trying further, it seemed the PostgreSQL datetime format can be specified
by the server, or the client. Our server default deviates from the '%Y-%m-%d
%H:%M:%S' format. I don't know if this is related to the PostgreSQL version 11.
I specified an environment variable in database.yml as follows:
environment:
PGDATESTYLE: "ISO, DMY"
After this I had to re-create the database (also with this client-side
environment variable set) to make everything work again.
Thanks for your reply.
Stijn
-----Original Message-----
From: Oliver Welter <[email protected]>
Sent: woensdag 26 augustus 2020 20:24
To: [email protected]
Subject: Re: [OpenXPKI-users] Unknown error (server workflow persister dbi
parse date error)
Hi Stijn,
we have an install running with Postgres 10.5 but I never tried v11 to be
honest. The error happens when OpenXPKI tries to parse the datetime string
received from either the workflow.workflow_last_update or
workflow_history.workflow_history_date column. The expected format is '%Y-%m-%d
%H:%M:%S'.
So can you please check what your DB returns and perhaps try to change the
column specification to match this representation.
Oliver
Am 24.08.20 um 16:47 schrieb Stijn Adriaensens:
> Hello all,
>
>
>
> After setting up a basic OpenXPKI configuration I'm getting the
> following error in the GUI, after trying to publish the CRL: "Unknown
> error (server workflow persister dbi parse date error)". The full
> openxpki server log is at the end of this mail, ending with
> "openxpki.system.ERROR
> I18N_OPENXPKI_SERVER_WORKFLOW_PERSISTER_DBI_PARSE_DATE_ERROR".
>
>
>
> The system is connected to an external database (PostgreSQL 11.4.11)
> and has a signer-ca and vault token accessible. The tokens are loaded
> using openxpkiadm on the server (no errors shown in the GUI when loading it).
>
>
>
> It seems that I'm getting the error whenever workflows are executed.
> Requesting a certificate as test also fails with the same error. I'm
> not able to find any specific requirements regarding the date format
> in PostgreSQL, only in the DBI persister source code:
> https://eur01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgith
> ub.com%2Fjonasbn%2Fperl-workflow%2Fblob%2Fmaster%2Flib%2FWorkflow%2FPe
> rsister%2FDBI.pm%23L58&data=02%7C01%7Cstijn.adriaensens%40realdolm
> en.com%7C584d67709dfe477dcd2308d849ed444e%7C1685007349774869916308e8d3
> 8eac81%7C1%7C0%7C637340630701634080&sdata=ok5u0qixepTr4EXioCuW3Bsr
> MRzmY6bjcVv78rYol4c%3D&reserved=0
> "# Default to old date format if not provided so we don't break old
> configurations."
>
>
>
> The table definition of the workflow table (created using the provided
> database initialization script for PostgreSQL).
>
> a4bapki=> \d workflow;
>
> Table "public.workflow"
>
> Column | Type | Collation |
> Nullable | Default
>
> ----------------------+-----------------------------+-----------+----------+---------
>
> workflow_id | numeric(49,0) | | not
> null |
>
> pki_realm | text | |
> |
>
> workflow_type | text | |
> |
>
> workflow_state | text | |
> |
>
> workflow_last_update | timestamp without time zone | |
> |
>
> workflow_proc_state | text | |
> |
>
> workflow_wakeup_at | numeric(49,0) | |
> |
>
> workflow_count_try | numeric(49,0) | |
> |
>
> workflow_reap_at | numeric(49,0) | |
> |
>
> workflow_archive_at | numeric(49,0) | |
> |
>
> workflow_session | text | |
> |
>
> watchdog_key | text | |
> |
>
> Indexes:
>
> "workflow_pkey" PRIMARY KEY, btree (workflow_id)
>
> "workflow_archive_index" btree (workflow_proc_state, watchdog_key,
> workflow_archive_at)
>
> "workflow_pki_realm_index" btree (pki_realm)
>
> "workflow_realm_type_index" btree (pki_realm, workflow_type)
>
> "workflow_reapat_index" btree (workflow_proc_state, watchdog_key,
> workflow_reap_at)
>
> "workflow_state_index" btree (pki_realm, workflow_state)
>
> "workflow_wakeup_index" btree (workflow_proc_state, watchdog_key,
> workflow_wakeup_at)
>
>
>
> I'm using the docker containers, and an externally hosted PostgreSQL
> database instance. Do you have any idea on where to look further?
>
>
>
> Best regards,
>
> Stijn
>
>
>
> Server logs:
>
> ---
>
> Starting OpenXPKI...
>
> .
>
> .
>
> .
>
> 2020/08/24 16:26:42 openxpki.audit.system.INFO server was started
> [pid=1|]
>
> 2020/08/24-16:26:42 OpenXPKI::Server (type Net::Server::Fork ->
> MultiType -> Net::Server::Fork) starting! pid(1)
>
> Binding to UNIX socket file "/var/openxpki/openxpki.socket"
>
> Group Not Defined. Defaulting to EGID '0'
>
> User Not Defined. Defaulting to EUID '0'
>
> Setting gid to "10205"
>
> Setting uid to "10205"
>
> 2020/08/24 16:26:52 INFO Initialize session purge from watchdog with
> interval 300 [pid=8|sid=cNSI]
>
> 2020/08/24 16:27:32 INFO New session created [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Login successful using authentication stack
> 'Operator' (user: 'raop', role: 'RA Operator') [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Loading 88 API plugins
> [pid=9|user=raop|role=RA
> Operator|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Loading 88 API plugins
> [pid=9|user=raop|role=RA
> Operator|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Instantiating workflow of with ID '' and type
> 'status_system' with current state 'INITIAL' [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Instantiated workflow object properly,
> persisting... [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Created volatile workflow for type
> status_system [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Persisted workflow with ID '0'; creating
> history... [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Created history object ok [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Workflow 0/status_system/INITIAL created
> [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Workflow instance 0 created for raop (type:
> 'status_system') [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Set new state 'SUCCESS' after action executed
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Workflow '0' updated ok
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Saved workflow with possible new state ok
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Workflow '0' updated ok
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Workflow 0/status_system/SUCCESS executed
> 'statsys_initalize' in state 'INITIAL'
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Workflow 0/status_system/SUCCESS changed from
> state 'INITIAL' [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Workflow '0' updated ok
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=status_system|wfid=0]
>
> 2020/08/24 16:27:39 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
> 2020/08/24 16:27:39 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
> 2020/08/24 16:27:40 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
> 2020/08/24 16:27:40 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
> 2020/08/24 16:27:42 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
> 2020/08/24 16:27:42 INFO Instantiating workflow of with ID '' and type
> 'ca_publish' with current state 'INITIAL' [pid=9|sid=njoD]
>
> 2020/08/24 16:27:42 INFO Instantiated workflow object properly,
> persisting... [pid=9|sid=njoD]
>
> 2020/08/24 16:27:42 INFO Created workflow ID 6399. [pid=9|sid=njoD]
>
> 2020/08/24 16:27:42 INFO Persisted workflow with ID '6399'; creating
> history... [pid=9|sid=njoD]
>
> 2020/08/24 16:27:42 INFO Created history object ok [pid=9|sid=njoD]
>
> 2020/08/24 16:27:42 INFO Workflow 6399/ca_publish/INITIAL created
> [pid=9|sid=njoD]
>
> 2020/08/24 16:27:42 INFO Workflow instance 6399 created for raop (type:
> 'ca_publish') [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Set new state 'CREATE_QUEUE' after action
> executed [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Saved workflow with possible new state ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow 6399/ca_publish/CREATE_QUEUE
> executed 'capub_initialize' in state 'INITIAL'
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow 6399/ca_publish/CREATE_QUEUE changed
> from state 'INITIAL' [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO State 'CREATE_QUEUE' marked to be run
> automatically; executing that state/action...
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Set new state 'LOAD_NEXT_CA' after action
> executed [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Saved workflow with possible new state ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow 6399/ca_publish/LOAD_NEXT_CA
> executed 'capub_create_ca_list' (autorun) in state 'CREATE_QUEUE'
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow 6399/ca_publish/LOAD_NEXT_CA changed
> from state 'CREATE_QUEUE' [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO State 'LOAD_NEXT_CA' marked to be run
> automatically; executing that state/action...
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Set new state 'PUBLISH_CACERT' after action
> executed [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Saved workflow with possible new state ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow 6399/ca_publish/PUBLISH_CACERT
> executed 'capub_get_next_ca' (autorun) in state 'LOAD_NEXT_CA'
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow 6399/ca_publish/PUBLISH_CACERT
> changed from state 'LOAD_NEXT_CA'
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO State 'PUBLISH_CACERT' marked to be run
> automatically; executing that state/action...
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:42 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Set new state 'PUBLISH_CRL' after action
> executed [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Saved workflow with possible new state ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Workflow 6399/ca_publish/PUBLISH_CRL executed
> 'capub_publish_cacert' (autorun) in state 'PUBLISH_CACERT'
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Workflow 6399/ca_publish/PUBLISH_CRL changed
> from state 'PUBLISH_CACERT'
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO State 'PUBLISH_CRL' marked to be run
> automatically; executing that state/action...
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 ERROR
> I18N_OPENXPKI_SERVER_WORKFLOW_ACTIVITY_TOOLS_PUBLISH_CRL_UNABLE_TO_LOA
> D_CRL; __CRL_SERIAL__ => EMPTY
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 openxpki.system.ERROR
> I18N_OPENXPKI_SERVER_WORKFLOW_ACTIVITY_TOOLS_PUBLISH_CRL_UNABLE_TO_LOA
> D_CRL; __CRL_SERIAL__ => EMPTY
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 ERROR Caught exception from action:
> I18N_OPENXPKI_SERVER_WORKFLOW_ACTIVITY_TOOLS_PUBLISH_CRL_UNABLE_TO_LOA
> D_CRL; __CRL_SERIAL__ => EMPTY; reset workflow to old state
> 'PUBLISH_CRL'
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 Workflow.ERROR Caught exception from action:
> I18N_OPENXPKI_SERVER_WORKFLOW_ACTIVITY_TOOLS_PUBLISH_CRL_UNABLE_TO_LOA
> D_CRL; __CRL_SERIAL__ => EMPTY; reset workflow to old state
> 'PUBLISH_CRL'
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Workflow '6399' updated ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Created necessary history objects ok
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 ERROR
> I18N_OPENXPKI_SERVER_WORKFLOW_ERROR_ON_EXECUTE; __ACTION__ =>
> capub_publish_crl, __ERROR__ =>
> I18N_OPENXPKI_SERVER_WORKFLOW_ACTIVITY_TOOLS_PUBLISH_CRL_UNABLE_TO_LOA
> D_CRL; __CRL_SERIAL__ => EMPTY, __EXCEPTION__ => OpenXPKI::Exception
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 openxpki.system.ERROR
> I18N_OPENXPKI_SERVER_WORKFLOW_ERROR_ON_EXECUTE; __ACTION__ =>
> capub_publish_crl, __ERROR__ =>
> I18N_OPENXPKI_SERVER_WORKFLOW_ACTIVITY_TOOLS_PUBLISH_CRL_UNABLE_TO_LOA
> D_CRL; __CRL_SERIAL__ => EMPTY, __EXCEPTION__ => OpenXPKI::Exception
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 ERROR Error executing workflow activity
> 'capub_initialize' on workflow id 6399 (type ca_publish):
> I18N_OPENXPKI_SERVER_WORKFLOW_ERROR_ON_EXECUTE; __ACTION__ =>
> capub_publish_crl, __ERROR__ =>
> I18N_OPENXPKI_SERVER_WORKFLOW_ACTIVITY_TOOLS_PUBLISH_CRL_UNABLE_TO_LOA
> D_CRL; __CRL_SERIAL__ => EMPTY, __EXCEPTION__ => OpenXPKI::Exception
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 openxpki.workflow.ERROR Error executing workflow
> activity 'capub_initialize' on workflow id 6399 (type ca_publish):
> I18N_OPENXPKI_SERVER_WORKFLOW_ERROR_ON_EXECUTE; __ACTION__ =>
> capub_publish_crl, __ERROR__ =>
> I18N_OPENXPKI_SERVER_WORKFLOW_ACTIVITY_TOOLS_PUBLISH_CRL_UNABLE_TO_LOA
> D_CRL; __CRL_SERIAL__ => EMPTY, __EXCEPTION__ => OpenXPKI::Exception
> [pid=9|sid=njoD|wftype=ca_publish|wfid=6399]
>
> 2020/08/24 16:27:43 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
> 2020/08/24 16:27:43 ERROR
> I18N_OPENXPKI_SERVER_WORKFLOW_PERSISTER_DBI_PARSE_DATE_ERROR
> [pid=9|sid=njoD]
>
> 2020/08/24 16:27:43 openxpki.system.ERROR
> I18N_OPENXPKI_SERVER_WORKFLOW_PERSISTER_DBI_PARSE_DATE_ERROR
> [pid=9|sid=njoD]
>
> 2020/08/24 16:27:43 INFO Loading 88 API plugins [pid=9|sid=njoD]
>
>
>
> _______________________________________________
> OpenXPKI-users mailing list
> [email protected]
> https://eur01.safelinks.protection.outlook.com/?url=https%3A%2F%2Flist
> s.sourceforge.net%2Flists%2Flistinfo%2Fopenxpki-users&data=02%7C01
> %7Cstijn.adriaensens%40realdolmen.com%7C584d67709dfe477dcd2308d849ed44
> 4e%7C1685007349774869916308e8d38eac81%7C1%7C0%7C637340630701634080&
> ;sdata=SXmZZslb70xqmNZLb6bylUpwVfwEgbX3oa2%2FavqOzSg%3D&reserved=0
>
--
Protect your environment - close windows and adopt a penguin!
_______________________________________________
OpenXPKI-users mailing list
[email protected]
https://eur01.safelinks.protection.outlook.com/?url=https%3A%2F%2Flists.sourceforge.net%2Flists%2Flistinfo%2Fopenxpki-users&data=02%7C01%7Cstijn.adriaensens%40realdolmen.com%7C584d67709dfe477dcd2308d849ed444e%7C1685007349774869916308e8d38eac81%7C1%7C0%7C637340630701634080&sdata=SXmZZslb70xqmNZLb6bylUpwVfwEgbX3oa2%2FavqOzSg%3D&reserved=0
_______________________________________________
OpenXPKI-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/openxpki-users
