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://github.com/jonasbn/perl-workflow/blob/master/lib/Workflow/Persister/DBI.pm#L58
>  “# 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_LOAD_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_LOAD_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_LOAD_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_LOAD_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_LOAD_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_LOAD_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_LOAD_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_LOAD_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://lists.sourceforge.net/lists/listinfo/openxpki-users
> 


-- 
Protect your environment -  close windows and adopt a penguin!


_______________________________________________
OpenXPKI-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/openxpki-users

Reply via email to