From b8d2764b7a8c9f2698f1df070f9ff35098abffbe Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 27 Aug 2018 14:43:10 +0200
Subject: [PATCH 01/22] Fix and optimize debug logging tests; raise required
 Test::More version

Test::More introduced arguments for subtests in version 1.001004.
Nevertheless the required version is now 1.001008 as this is the one
included in Debian Jessie.
---
 core/server/MANIFEST                          |  1 -
 core/server/Makefile.PL                       |  2 +-
 core/server/OpenXPKI/Client/SCEP.pm           |  2 +
 core/server/t/08_debug/01_using.t             | 78 ++++++++-------
 core/server/t/08_debug/02_color.t             | 94 +++++++++---------
 core/server/t/08_debug/03_invalid.t           | 97 ++++++++++---------
 .../t/08_debug/04_use_without_package.t       | 48 ---------
 7 files changed, 149 insertions(+), 173 deletions(-)
 delete mode 100644 core/server/t/08_debug/04_use_without_package.t

diff --git a/core/server/MANIFEST b/core/server/MANIFEST
index b2b2a2f861..bebf4c16b4 100644
--- a/core/server/MANIFEST
+++ b/core/server/MANIFEST
@@ -644,7 +644,6 @@ t/05_base/03_config.t
 t/08_debug/01_using.t
 t/08_debug/02_color.t
 t/08_debug/03_invalid.t
-t/08_debug/04_use_without_package.t
 t/08_debug/main.pl
 t/08_debug/TestModuleColor.pm
 t/08_debug/TestModuleInvalid.pm
diff --git a/core/server/Makefile.PL b/core/server/Makefile.PL
index 594074aaf3..b85694ec68 100644
--- a/core/server/Makefile.PL
+++ b/core/server/Makefile.PL
@@ -375,7 +375,7 @@ WriteMakefile(
         'Sub::Exporter'                 => 0,           # for OpenXPKI::MooseParams
         'Sys::SigAction'                => '0.06',
         'Template'                      => '2.15',
-        'Test::More'                    => '0.98',
+        'Test::More'                    => '1.001008',
         'Test::Pod::Coverage'           => '1.00',
         'Test::Pod'                     => '1.00',
         'Text::CSV_XS'                  => '0.23',
diff --git a/core/server/OpenXPKI/Client/SCEP.pm b/core/server/OpenXPKI/Client/SCEP.pm
index 762ff88c4c..ea2d2ec574 100644
--- a/core/server/OpenXPKI/Client/SCEP.pm
+++ b/core/server/OpenXPKI/Client/SCEP.pm
@@ -165,6 +165,8 @@ script that acts as the SCEP server.
 
 PKI Realm to access (must match server configuration).
 
+=back
+
 =head2 send_request
 
 Sends SCEP request to OpenXPKI server, expects operation and message as
diff --git a/core/server/t/08_debug/01_using.t b/core/server/t/08_debug/01_using.t
index dafa6bcd0b..85f8cd9477 100644
--- a/core/server/t/08_debug/01_using.t
+++ b/core/server/t/08_debug/01_using.t
@@ -2,43 +2,51 @@ use strict;
 use warnings;
 use Test::More;
 use English;
-plan tests => 18;
+plan tests => 5;
 
 use_ok('OpenXPKI::Debug');
 
-note "Standard debug usage";
-my $stderr = `$^X -It/08_debug t/08_debug/main.pl TestModule.pm 1 2>&1`;
-ok(! $CHILD_ERROR, 'main.pl execution');
-like($stderr,
-     qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
-     'Debug message cotains a date and time'
-);
-like($stderr, qr{ DEBUG:1 }xms, 'Debug contains DEBUG:1 string');
-unlike($stderr, qr{ DEBUG:2 }xms, 'Debug does not contain DEBUG:2 string');
-like($stderr,
-     qr{ TestModule::START }xms,
-     'Debug contains module name and method'
- );
-like($stderr, qr{ loglevel\ 1 }xms, 'Debug contains literal log message');
-like($stderr, qr{ code:\ 2 }xms, 'Debug contains executed log message');
-
-# debug level 2
-$stderr = `$^X -It/08_debug t/08_debug/main.pl TestModule.pm 2 2>&1`;
-ok(! $CHILD_ERROR, 'main.pl execution');
-like($stderr,
-     qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
-     'Debug message cotains a date and time'
-);
-like($stderr, qr{ DEBUG:1 }xms, 'Debug contains DEBUG:1 string');
-like($stderr, qr{ DEBUG:2 }xms, 'Debug contains DEBUG:2 string');
-unlike($stderr, qr{ DEBUG:16 }xms, 'Debug does not contain DEBUG:16 string');
-like($stderr,
-     qr{ TestModule::START }xms,
-     'Debug contains module name and method'
- );
-like($stderr, qr{ loglevel\ 1 }xms, 'Debug contains literal log message');
-like($stderr, qr{ loglevel\ 2 }xms, 'Debug contains literal log message');
-unlike($stderr, qr{ loglevel\ 4 }xms, 'Debug contains literal log message');
-like($stderr, qr{ code:\ 2 }xms, 'Debug contains executed log message');
+my $test = sub {
+    my ($module, $loglevel) = @_;
+    # map desired loglevel to a bitmask
+    my $bitmask = { 1 => 0b01, 2 => 0b11, }->{$loglevel};
+
+    plan tests => 6 + ($loglevel == 1 ? 2 : 4);
+
+    my $stderr = `$^X -It/08_debug t/08_debug/main.pl $module.pm $bitmask 2>&1`;
+    ok(! $CHILD_ERROR, 'main.pl execution');
+    like($stderr,
+         qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
+         'date and time'
+    );
+    like($stderr, qr{ DEBUG:1 }xms, '"DEBUG:1" string');
+
+    if ($loglevel == 1) {
+        unlike($stderr, qr{ DEBUG:2 }xms, '"DEBUG:2" string should not be there');
+    }
+    else {
+        like($stderr, qr{ DEBUG:2 }xms, '"DEBUG:2" string');
+        unlike($stderr, qr{ DEBUG:4 }xms, '"DEBUG:4" string should not be there');
+    }
+
+    like($stderr, qr/ ${module}::START /xms, 'module name and method');
+    like($stderr, qr{ loglevel\ 1 }xms, 'literal log message (level 1)');
+
+    if ($loglevel == 1) {
+        unlike($stderr, qr{ loglevel\ 2 }xms, 'literal log message (level 2) should not be there');
+    }
+    else {
+        like($stderr, qr{ loglevel\ 2 }xms, 'literal log message (level 2)');
+        unlike($stderr, qr{ loglevel\ 4 }xms, 'literal log message (level 4) should not be there');
+    }
+
+    like($stderr, qr{ code:\ 2 }xms, 'result of code execution');
+};
+
+subtest 'Standard debug output, log level 1', $test => ("TestModule", 1);
+subtest 'Standard debug output, log level 2', $test => ("TestModule", 2);
+
+subtest 'Standard debug output, no explicit package spec, log level 1', $test => ("TestModuleUseWithout", 1);
+subtest 'Standard debug output, no explicit package spec, log level 2', $test => ("TestModuleUseWithout", 2);
 
 1;
diff --git a/core/server/t/08_debug/02_color.t b/core/server/t/08_debug/02_color.t
index bdf6151eae..640a9dfb04 100644
--- a/core/server/t/08_debug/02_color.t
+++ b/core/server/t/08_debug/02_color.t
@@ -2,7 +2,7 @@ use strict;
 use warnings;
 use Test::More;
 use English;
-plan tests => 20;
+plan tests => 3;
 
 eval {
     use Term::ANSIColor;
@@ -13,48 +13,54 @@ if ($EVAL_ERROR) {
 
 use_ok('OpenXPKI::Debug');
 
-note "Colored debug output";
-# first check that everything works with the colored module too
-my $stderr = `$^X -It/08_debug t/08_debug/main.pl TestModuleColor.pm 1 2>&1`;
-ok(! $CHILD_ERROR, 'main.pl execution');
-like($stderr,
-     qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
-     'Debug message cotains a date and time'
-);
-like($stderr, qr{ DEBUG:1 }xms, 'Debug contains DEBUG:1 string');
-unlike($stderr, qr{ DEBUG:2 }xms, 'Debug does not contain DEBUG:2 string');
-like($stderr,
-     qr{ TestModuleColor::START }xms,
-     'Debug contains module name and method'
- );
-like($stderr, qr{ loglevel\ 1 }xms, 'Debug contains literal log message');
-like($stderr, qr{ code:\ 2 }xms, 'Debug contains executed log message');
-
-# debug level 2
-$stderr = `$^X -It/08_debug t/08_debug/main.pl TestModuleColor.pm 2 2>&1`;
-ok(! $CHILD_ERROR, 'main.pl execution');
-like($stderr,
-     qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
-     'Debug message cotains a date and time'
-);
-like($stderr, qr{ DEBUG:1 }xms, 'Debug contains DEBUG:1 string');
-like($stderr, qr{ DEBUG:2 }xms, 'Debug contains DEBUG:2 string');
-unlike($stderr, qr{ DEBUG:16 }xms, 'Debug does not contain DEBUG:16 string');
-like($stderr,
-     qr{ TestModuleColor::START }xms,
-     'Debug contains module name and method'
- );
-like($stderr, qr{ loglevel\ 1 }xms, 'Debug contains literal log message');
-like($stderr, qr{ loglevel\ 2 }xms, 'Debug contains literal log message');
-unlike($stderr, qr{ loglevel\ 4 }xms, 'Debug contains literal log message');
-like($stderr, qr{ code:\ 2 }xms, 'Debug contains executed log message');
-
-# here are the color specific tests ...
-
-my $red_start = chr(0x1b) . '\[31m';
-my $color_stop  = chr(0x1b) . '\[0m';
-
-like($stderr, qr{ $red_start }xms, 'Output contains ANSI red start code');
-like($stderr, qr{ $color_stop }xms, 'Output contains ANSI stop coloring code');
+my $test = sub {
+    my ($loglevel) = @_;
+    # map desired loglevel to a bitmask
+    my $bitmask = { 1 => 0b01, 2 => 0b11, }->{$loglevel};
+
+    plan tests => 6 + ($loglevel == 1 ? 2 : 6);
+
+    my $stderr = `$^X -It/08_debug t/08_debug/main.pl TestModuleColor.pm $bitmask 2>&1`;
+
+    ok(! $CHILD_ERROR, 'main.pl execution');
+    like($stderr,
+         qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
+         'date and time'
+    );
+    like($stderr, qr{ DEBUG:1 }xms, '"DEBUG:1" string');
+
+    if ($loglevel == 1) {
+        unlike($stderr, qr{ DEBUG:2 }xms, '"DEBUG:2" string should not be there');
+    }
+    else {
+        like($stderr, qr{ DEBUG:2 }xms, '"DEBUG:2" string');
+        unlike($stderr, qr{ DEBUG:4 }xms, '"DEBUG:4" string should not be there');
+    }
+
+    like($stderr, qr{ TestModuleColor::START }xms, 'module name and method');
+    like($stderr, qr{ loglevel\ 1 }xms, 'literal log message (level 1)');
+
+    if ($loglevel == 1) {
+        unlike($stderr, qr{ loglevel\ 2 }xms, 'literal log message (level 2) should not be there');
+    }
+    else {
+        like($stderr, qr{ loglevel\ 2 }xms, 'literal log message (level 2)');
+        unlike($stderr, qr{ loglevel\ 4 }xms, 'literal log message (level 4) should not be there');
+    }
+
+    like($stderr, qr{ code:\ 2 }xms, 'result of code execution');
+
+    if ($loglevel == 2) {
+        # the color specific tests
+        my $red_start = chr(0x1b) . '\[31m';
+        my $color_stop  = chr(0x1b) . '\[0m';
+
+        like($stderr, qr{ $red_start }xms, 'Output contains ANSI red start code');
+        like($stderr, qr{ $color_stop }xms, 'Output contains ANSI stop coloring code');
+    }
+};
+
+subtest 'Colored debug output, log level 1', $test => 1;
+subtest 'Colored debug output, log level 2', $test => 2;
 
 1;
diff --git a/core/server/t/08_debug/03_invalid.t b/core/server/t/08_debug/03_invalid.t
index f7791a26b6..75a8d3407a 100644
--- a/core/server/t/08_debug/03_invalid.t
+++ b/core/server/t/08_debug/03_invalid.t
@@ -2,52 +2,61 @@ use strict;
 use warnings;
 use Test::More;
 use English;
-plan tests => 24;
+plan tests => 3;
 
 use_ok('OpenXPKI::Debug');
 
-note "Catching invalid debug output";
-# first check that everything works with the invalid module
-my $stderr = `$^X -It/08_debug t/08_debug/main.pl TestModuleInvalid.pm 1 2>&1`;
-ok(! $CHILD_ERROR, 'main.pl execution');
-like($stderr,
-     qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
-     'Debug message cotains a date and time'
-);
-like($stderr, qr{ DEBUG:1 }xms, 'Debug contains DEBUG:1 string');
-unlike($stderr, qr{ DEBUG:2 }xms, 'Debug does not contain DEBUG:2 string');
-like($stderr,
-     qr{ TestModuleInvalid::START }xms,
-     'Debug contains module name and method'
- );
-like($stderr, qr{ loglevel\ 1 }xms, 'Debug contains literal log message');
-like($stderr, qr{ code:\ 2 }xms, 'Debug contains executed log message');
-
-# debug level 16
-$stderr = `$^X -It/08_debug t/08_debug/main.pl TestModuleInvalid.pm 16 2>&1`;
-ok(! $CHILD_ERROR, 'main.pl execution');
-like($stderr,
-     qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
-     'Debug message cotains a date and time'
-);
-like($stderr, qr{ DEBUG:1 }xms, 'Debug contains DEBUG:1 string');
-like($stderr, qr{ DEBUG:2 }xms, 'Debug contains DEBUG:2 string');
-like($stderr, qr{ DEBUG:16 }xms, 'Debug contains DEBUG:16 string');
-unlike($stderr, qr{ DEBUG:32000 }xms, 'Debug does not contain DEBUG:32000 string');
-like($stderr,
-     qr{ TestModuleInvalid::START }xms,
-     'Debug contains module name and method'
- );
-like($stderr, qr{ loglevel\ 1 }xms, 'Debug contains literal log message');
-like($stderr, qr{ loglevel\ 2 }xms, 'Debug contains literal log message');
-like($stderr, qr{ loglevel\ 4 }xms, 'Debug contains literal log message');
-like($stderr, qr{ loglevel\ 16 }xms, 'Debug contains literal log message');
-like($stderr, qr{ code:\ 2 }xms, 'Debug contains executed log message');
-
-# here are the invalidity specific tests ...
-like($stderr, qr{ Invalid\ DEBUG\ statement }xms, 'Invalid debug statement caught');
-like($stderr, qr{ Invalid\ DEBUG\ statement: .* Can't\ find\ string\ terminator }xms, 'Unclosed string caught');
-like($stderr, qr{ Invalid\ DEBUG\ statement: .* Can't\ locate\ class\ method }xms, 'Unknown method caught');
-like($stderr, qr{ Invalid\ DEBUG\ statement: .* Undefined\ subroutine }xms, 'Unknown package caught');
+my $test = sub {
+    my ($loglevel) = @_;
+    # map desired loglevel to a bitmask
+    my $bitmask = { 1 => 0b01, 16 => 0b11111, }->{$loglevel};
+
+    plan tests => 6 + ($loglevel == 1 ? 2 : 12);
+
+    my $stderr = `$^X -It/08_debug t/08_debug/main.pl TestModuleInvalid.pm $bitmask 2>&1`;
+
+    ok(! $CHILD_ERROR, 'main.pl execution');
+    like($stderr,
+         qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
+         'date and time'
+    );
+    like($stderr, qr{ DEBUG:1 }xms, '"DEBUG:1" string');
+
+    if ($loglevel == 1) {
+        unlike($stderr, qr{ DEBUG:2 }xms, '"DEBUG:2" string should not be there');
+    }
+    else {
+        like($stderr, qr{ DEBUG:2 }xms, '"DEBUG:2" string');
+        like($stderr, qr{ DEBUG:4 }xms, '"DEBUG:4" string');
+        like($stderr, qr{ DEBUG:16 }xms, '"DEBUG:16" string');
+        unlike($stderr, qr{ DEBUG:256 }xms, '"DEBUG:256" string should not be there');
+    }
+
+    like($stderr, qr{ TestModuleInvalid::START }xms, 'module name and method');
+    like($stderr, qr{ loglevel\ 1 }xms, 'literal log message (level 1)');
+
+    if ($loglevel == 1) {
+        unlike($stderr, qr{ loglevel\ 2 }xms, 'literal log message (level 2) should not be there');
+    }
+    else {
+        like($stderr, qr{ loglevel\ 2 }xms, 'literal log message (level 2)');
+        like($stderr, qr{ loglevel\ 4 }xms, 'literal log message (level 4)');
+        like($stderr, qr{ loglevel\ 16 }xms, 'literal log message (level 16)');
+        unlike($stderr, qr{ loglevel\ 256 }xms, 'literal log message (level 256) should not be there');
+    }
+
+    like($stderr, qr{ code:\ 2 }xms, 'result of code execution');
+
+    if ($loglevel == 16) {
+        # the invalidity specific tests
+        like($stderr, qr{ Invalid\ DEBUG\ statement }xms, 'Invalid debug statement caught');
+        like($stderr, qr{ Invalid\ DEBUG\ statement: .* Can't\ find\ string\ terminator }xms, 'Unclosed string caught');
+        like($stderr, qr{ Invalid\ DEBUG\ statement: .* Can't\ locate\ class\ method }xms, 'Unknown method caught');
+        like($stderr, qr{ Invalid\ DEBUG\ statement: .* Undefined\ subroutine }xms, 'Unknown package caught');
+    }
+};
+
+subtest 'Partly invalid debug statements, log level 1', $test => 1;
+subtest 'Partly invalid debug statements, log level 16', $test => 16;
 
 1;
diff --git a/core/server/t/08_debug/04_use_without_package.t b/core/server/t/08_debug/04_use_without_package.t
deleted file mode 100644
index f93ffb04fb..0000000000
--- a/core/server/t/08_debug/04_use_without_package.t
+++ /dev/null
@@ -1,48 +0,0 @@
-use strict;
-use warnings;
-use Test::More;
-use English;
-plan tests => 20;
-
-use_ok('OpenXPKI::Debug');
-
-note "Use without specifying package name";
-# check that everything works the same without specifying our name in
-# use OpenXPKI::Debug ...
-my $stderr = `$^X -It/08_debug t/08_debug/main.pl TestModuleUseWithout.pm 1 2>&1`;
-ok(! $CHILD_ERROR, 'main.pl execution');
-like($stderr,
-     qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
-     'Debug message cotains a date and time'
-);
-like($stderr, qr{ DEBUG:1 }xms, 'Debug contains DEBUG:1 string');
-unlike($stderr, qr{ DEBUG:2 }xms, 'Debug does not contain DEBUG:2 string');
-like($stderr,
-     qr{ TestModuleUseWithout::START }xms,
-     'Debug contains module name and method'
- );
-like($stderr, qr{ loglevel\ 1 }xms, 'Debug contains literal log message');
-like($stderr, qr{ code:\ 2 }xms, 'Debug contains executed log message');
-
-# debug level 16
-$stderr = `$^X -It/08_debug t/08_debug/main.pl TestModuleUseWithout.pm 16 2>&1`;
-ok(! $CHILD_ERROR, 'main.pl execution');
-like($stderr,
-     qr{ ^\d{4}-\d{2}-\d{2}\ \d{2}:\d{2}:\d{2} }xms,
-     'Debug message cotains a date and time'
-);
-like($stderr, qr{ DEBUG:1 }xms, 'Debug contains DEBUG:1 string');
-like($stderr, qr{ DEBUG:2 }xms, 'Debug contains DEBUG:2 string');
-like($stderr, qr{ DEBUG:16 }xms, 'Debug contains DEBUG:16 string');
-unlike($stderr, qr{ DEBUG:32000 }xms, 'Debug does not contain DEBUG:32000 string');
-like($stderr,
-     qr{ TestModuleUseWithout::START }xms,
-     'Debug contains module name and method'
- );
-like($stderr, qr{ loglevel\ 1 }xms, 'Debug contains literal log message');
-like($stderr, qr{ loglevel\ 2 }xms, 'Debug contains literal log message');
-like($stderr, qr{ loglevel\ 4 }xms, 'Debug contains literal log message');
-like($stderr, qr{ loglevel\ 16 }xms, 'Debug contains literal log message');
-like($stderr, qr{ code:\ 2 }xms, 'Debug contains executed log message');
-
-1;

From b83890dcf04d9dbf8a62776f15ccc1a1f3133bdf Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 27 Aug 2018 17:53:29 +0200
Subject: [PATCH 02/22] Fix missing PEM data when importing certificates

---
 .../API2/Plugin/Cert/import_certificate.pm    | 29 +++++++++++--------
 1 file changed, 17 insertions(+), 12 deletions(-)

diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm b/core/server/OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm
index cd09b8c1d3..c46b57f628 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm
@@ -26,25 +26,28 @@ use OpenXPKI::Server::Database; # to get AUTO_ID
 Parameters:
 
 =over
+=item * C<XXX> I<Bool> - XXX. Default: XXX
 
-=item * B<DATA>, certificate data (PEM encoded)
+=item * C<data> I<Str> - certificate data (PEM encoded)
 
-=item * B<PKI_REALM> (optional), set the PKI realm to this value (might be overridden by an
-issuer's realm)
+=item * C<pki_realm> I<Str> - set the PKI realm to this value (optional, might be
+overridden by an issuer's realm)
 
-=item * B<FORCE_NOCHAIN> (optional), 1 = import certificate even if issuer is
+=item * C<force_nochain> I<Str> - 1 = import certificate even if issuer is
 unknown (then I<issuer_identifier> will not be set) or has an incomplete
-signature chain.
+signature chain. Default: 0
 
-=item * B<FORCE_ISSUER> (optional), 1 = enforce import even if it has an invalid
-signature chain (i.e. verification failed).
+=item * C<force_issuer> I<Bool> - 1 = enforce import even if it has an invalid
+signature chain (i.e. verification failed). Default: 0
 
-=item * B<FORCE_NOVERIFY> (optional), 1 = do not validate signature chain (e.g.
-if one of the certificates' CA has expired)
+=item * C<force_noverify> I<Bool> - 1 = do not validate signature chain (e.g.
+if one of the certificates' CAs has expired). Default: 0
 
-=item * B<REVOKED> (optional), Set to 1 to set the certificate status to "REVOKED"
+=item * C<revoked> I<Bool> - set to 1 to set the certificate status to
+I<REVOKED>. Default: 0
 
-=item * B<UPDATE> (optional), Do not throw an exception if certificate already exists, update it instead
+=item * C<update> I<Bool> - do not throw an exception if certificate already
+exists, update it instead. Default: 0
 
 =back
 
@@ -95,6 +98,8 @@ command "import_certificate" => {
     my $cert_hash = {
         status => 'ISSUED',
         identifier => $cert_identifier,
+        data => $x509->pem,
+        # FIXME public_key is missing !
         issuer_dn => $x509->get_issuer,
         cert_key => $x509->get_serial,
         subject => $x509->get_subject,
@@ -186,7 +191,7 @@ command "import_certificate" => {
         if (!$valid) {
             # force the invalid issuer
             if ($params->force_issuer) {
-                CTX('log')->system->warn("Importing certificate with invalid chain with force! $cert_identifier / " . $x509->get_subject());
+                CTX('log')->system->warn("Forced import of certificate with invalid! $cert_identifier / " . $x509->get_subject());
                 CTX('log')->audit('system')->warn('certificate import without chain validation', {
                     certid    => $cert_identifier,
                     key       => $x509->get_subject_key_id(),

From 27a897cabf4976c3d0ebc21762e0c178a9681c3e Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 27 Aug 2018 17:55:51 +0200
Subject: [PATCH 03/22] Add debug statement

---
 core/server/OpenXPKI/Server/Database.pm | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/core/server/OpenXPKI/Server/Database.pm b/core/server/OpenXPKI/Server/Database.pm
index 57de334ec8..c26bd44d31 100644
--- a/core/server/OpenXPKI/Server/Database.pm
+++ b/core/server/OpenXPKI/Server/Database.pm
@@ -339,6 +339,7 @@ sub run {
     $self->log->trace(sprintf "DB query: %s", $query_string) if $self->log->is_trace;
 
     my $rownum = $sth->execute;
+    ##! 16: "$rownum rows affected"
 
     return $return_rownum ? $rownum : $sth;
 }
@@ -519,7 +520,7 @@ sub commit {
         $self->log->debug("commit() was called without indicating a transaction start via start_txn() first")
     }
 
-    ##! 16: "Commit of changes"
+    ##! 16: "Commiting changes"
     $self->dbh->commit;
     $self->_clear_txn_starter;
 }

From e64e7a8c05afeb7412155d9ecf5e756136975966 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 27 Aug 2018 17:56:21 +0200
Subject: [PATCH 04/22] Document how to enable debugging in tests

---
 core/server/t/lib/OpenXPKI/Test.pm | 17 ++++++++++++++++-
 1 file changed, 16 insertions(+), 1 deletion(-)

diff --git a/core/server/t/lib/OpenXPKI/Test.pm b/core/server/t/lib/OpenXPKI/Test.pm
index 591b41014c..f93031cb61 100644
--- a/core/server/t/lib/OpenXPKI/Test.pm
+++ b/core/server/t/lib/OpenXPKI/Test.pm
@@ -21,7 +21,6 @@ Start an OpenXPKI test server:
     $client->init_session;
     $client->login("caop");
 
-
 =head1 DESCRIPTION
 
 This class is the central new (as of 2017) test vehicle for OpenXPKI that sets
@@ -115,6 +114,22 @@ available for QA tests):
 
     my $oxitest = OpenXPKI::Test->new(with => [ qw( SampleConfig Server ) ]);
 
+=head2 Debugging
+
+To display debug statements just use L<OpenXPKI::Debug> in your test files
+B<before> you use C<OpenXPKI::Test>:
+
+    # e.g. in t/mytest.t
+    use strict;
+    use warnings;
+
+    use Test::More;
+
+    use OpenXPKI::Debug;
+    BEGIN { $OpenXPKI::Debug::LEVEL{'OpenXPKI::Server::Database.*'} = 0b1111111 }
+
+    use OpenXPKI::Test;
+
 =cut
 
 # Core modules

From fddbc2a76b1705dff6274cfb63aa5ccb523a7a41 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 27 Aug 2018 17:57:10 +0200
Subject: [PATCH 05/22] Identify certificates by ID in tests

---
 core/server/t/lib/OpenXPKI/Test.pm                     |  2 +-
 core/server/t/lib/OpenXPKI/Test/CertHelper/Database.pm | 10 +++++-----
 2 files changed, 6 insertions(+), 6 deletions(-)

diff --git a/core/server/t/lib/OpenXPKI/Test.pm b/core/server/t/lib/OpenXPKI/Test.pm
index f93031cb61..ac57c7f45a 100644
--- a/core/server/t/lib/OpenXPKI/Test.pm
+++ b/core/server/t/lib/OpenXPKI/Test.pm
@@ -992,7 +992,7 @@ sub delete_testcerts {
     my $certhelper = $self->certhelper_database;
 
     $self->dbi->start_txn;
-    $self->dbi->delete(from => 'certificate', where => { subject_key_identifier => $certhelper->all_cert_subject_key_ids } );
+    $self->dbi->delete(from => 'certificate', where => { identifier => $certhelper->all_cert_ids } );
     $self->dbi->delete(from => 'aliases',     where => { identifier => [ map { $_->db->{identifier} } values %{$certhelper->_certs} ] } );
     $self->dbi->delete(from => 'crl',         where => { issuer_identifier => [ map { $_->id } values %{$certhelper->_certs} ] } );
     $self->dbi->commit;
diff --git a/core/server/t/lib/OpenXPKI/Test/CertHelper/Database.pm b/core/server/t/lib/OpenXPKI/Test/CertHelper/Database.pm
index 881080a187..9547841cd1 100644
--- a/core/server/t/lib/OpenXPKI/Test/CertHelper/Database.pm
+++ b/core/server/t/lib/OpenXPKI/Test/CertHelper/Database.pm
@@ -149,15 +149,15 @@ sub crl {
     return $self->_crls->{$realm_gen};
 }
 
-=head2 all_cert_subject_key_ids
+=head2 all_cert_ids
 
-Returns an ArrayRef with the "subject_key_identifier" of all test
-certificates handled by this class.
+Returns an ArrayRef with the internal "identifier" of all test certificates
+handled by this class.
 
 =cut
-sub all_cert_subject_key_ids {
+sub all_cert_ids {
     my $self = shift;
-    return [ map { $_->subject_key_id } values %{$self->_certs} ];
+    return [ map { $_->id } values %{$self->_certs} ];
 }
 
 =head2 cert_names_where

From 99b814081f32c1e146e30c97278186172bdfedcc Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 27 Aug 2018 17:57:42 +0200
Subject: [PATCH 06/22] Add test to check imported certificate data

---
 qatest/backend/api2/13_import_certificate.t | 14 +++++++++++---
 1 file changed, 11 insertions(+), 3 deletions(-)

diff --git a/qatest/backend/api2/13_import_certificate.t b/qatest/backend/api2/13_import_certificate.t
index 62e9a1633b..0ce0ae0776 100644
--- a/qatest/backend/api2/13_import_certificate.t
+++ b/qatest/backend/api2/13_import_certificate.t
@@ -17,11 +17,10 @@ use Test::Exception;
 
 # Project modules
 use lib $Bin, "$Bin/../../lib", "$Bin/../../../core/server/t/lib";
+# use OpenXPKI::Debug; BEGIN { $OpenXPKI::Debug::LEVEL{'OpenXPKI::Server::Database.*'} = 0b1111111 }
 use OpenXPKI::Test;
 
-
-plan tests => 13;
-
+plan tests => 15;
 
 =pod
 
@@ -101,6 +100,15 @@ lives_and {
     is $result->{identifier}, $result->{issuer_identifier};
 } "Import and recognize self signed root certificate";
 
+use_ok "OpenXPKI::Crypt::X509";
+
+lives_and {
+    my $cert_id = $dbdata->cert("alpha_root_2")->id;
+    my $result = $oxitest->api2_command("get_cert" => { identifier => $cert_id, format => 'PEM' });
+    my $cert = OpenXPKI::Crypt::X509->new($result); # initialize with PEM data
+    is $cert->cert_identifier, $cert_id;
+} "Querying imported certificate matches original data";
+
 # Second import should fail
 throws_ok {
     $oxitest->api2_command("import_certificate" => { data => $cert1_pem });

From 0f858f312e92cfd2dfcc6d5adadb4d6d820a3ed1 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 27 Aug 2018 18:05:59 +0200
Subject: [PATCH 07/22] Fix POD

---
 .../OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm       | 1 -
 1 file changed, 1 deletion(-)

diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm b/core/server/OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm
index c46b57f628..eec383d411 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Cert/import_certificate.pm
@@ -26,7 +26,6 @@ use OpenXPKI::Server::Database; # to get AUTO_ID
 Parameters:
 
 =over
-=item * C<XXX> I<Bool> - XXX. Default: XXX
 
 =item * C<data> I<Str> - certificate data (PEM encoded)
 

From 698451bd27a9667cbd2bfccf583f1e67bcada0d0 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Tue, 28 Aug 2018 18:07:54 +0200
Subject: [PATCH 08/22] Implement ACL checks for
 "search_workflow_instances_count"; refactoring

---
 .../Workflow/search_workflow_instances.pm     | 147 ++++++++++--------
 qatest/backend/api2/43_workflow_acl.t         |  35 ++++-
 2 files changed, 113 insertions(+), 69 deletions(-)

diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
index 476204a9e0..6c9af6fa8a 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
@@ -24,6 +24,12 @@ coerce 'ArrayOrAlphaPunct',
     from 'AlphaPunct',
     via { [ $_ ] };
 
+has 'count_only' => (
+    isa => 'Bool',
+    is => 'rw',
+    default => 0,
+);
+
 # helper / cache: maps each (queried) workflow type to the ACL defined for the current user's role
 has 'acl_by_wftype' => (
     isa => 'HashRef',
@@ -99,29 +105,19 @@ command "search_workflow_instances" => {
     return_attributes => {isa => 'ArrayRef', default => sub { [] } },
 } => sub {
     my ($self, $params) = @_;
-
-    # build db query parameters
-    my %sql_params = (
-        %{ $self->_search_query_params($params, $params->check_acl) },
-        %{ $self->_search_query_params_exclusive($params) },
-    );
-
-    # run SELECT query
-    my $result = CTX('dbi')->select(
-        %sql_params,
-    )->fetchall_arrayref({});
-
-    # ACLs part 3: filter result by applying ACL checks of type regex
-    if ($params->check_acl) {
-        $result = [ grep {
-            my $acl = $self->acl_by_wftype->{ $_->{workflow_type} };
-            $acl !~ /^(any|self|others)$/    # ACL of type regex?
-                ? $_->{creator} =~ qr/$acl/  # --> apply it
-                : 1
-        } @$result ];
-    }
-
-    return $result;
+    ##! 1: "start"
+
+    my $columns = [ qw(
+        workflow_last_update
+        workflow.workflow_id
+        workflow_type
+        workflow_state
+        workflow_proc_state
+        workflow_wakeup_at
+        pki_realm
+    ) ];
+
+    return $self->_search($params, $columns);
 };
 
 =head2 search_workflow_instances_count
@@ -129,7 +125,10 @@ command "search_workflow_instances" => {
 Searches workflow instances using the given parameters and returns the number
 of workflows found.
 
-see search_workflow_instances, limit and order fields are not applicable.
+See L</search_workflow_instances> for available parameters. Note that for
+compatibility with I<search_workflow_instances> the following parameters are
+accepted but ignored: C<attribute>, C<return_attributes>, C<start>, C<limit>,
+C<order>, C<reverse>.
 
 =cut
 command "search_workflow_instances_count" => {
@@ -138,40 +137,67 @@ command "search_workflow_instances_count" => {
     type       => { isa => 'ArrayOrAlphaPunct', coerce => 1, },
     state      => { isa => 'ArrayOrAlphaPunct', coerce => 1, },
     proc_state => { isa => 'AlphaPunct', },
+    check_acl  => { isa => 'Bool', default => 0 },
+    # these are ignored, but included to be compatible to "search_workflow_instances":
     attribute  => { isa => 'ArrayRef|HashRef', },
+    start      => { isa => 'Int', },
+    limit      => { isa => 'Int', },
+    order      => { isa => 'Str', },
+    reverse    => { isa => 'Bool', },
     return_attributes => {isa => 'ArrayRef', },
 } => sub {
     my ($self, $params) = @_;
 
-    $params->return_attributes([]);
+    ##! 1: "start"
+
+    $params->attribute([]);
+    $params->clear_start;
+    $params->clear_limit;
+    $params->clear_order;
+    $params->clear_reverse;
+
+    $self->count_only(1);
 
-    my $sql_params = $self->_search_query_params($params, 0);
-    my $result = CTX('dbi')->select_one(
-        %{ $sql_params },
-        columns => [ 'COUNT(workflow.workflow_id)|amount' ],
-    );
+    # 'workflow_type' and 'creator' needed to apply regex ACLs later on
+    $params->return_attributes([ 'creator' ]);
+    my $columns = [ qw( workflow_type ) ];
+    my $result = $self->_search($params, $columns);
 
-    ##! 1: "finished"
-    return $result->{amount};
+    return scalar @$result;
 };
 
-sub _search_query_params {
-    my ($self, $args, $check_acl) = @_;
+# Execute search and apply ACL checks
+sub _search {
+    my ($self, $params, $columns) = @_;
+
+    my %sql = %{ $self->_make_query_params($params, $columns) };
+
+    # run SELECT query
+    my $result = CTX('dbi')->select(%sql)->fetchall_arrayref({});
+
+    # ACLs part 3: apply ACL checks of type RegEx by filtering 'creator'
+    if ($params->check_acl) {
+        $result = [ grep {
+            my $acl = $self->acl_by_wftype->{ $_->{workflow_type} };
+            $acl !~ /^(any|self|others)$/    # ACL of type regex?
+                ? $_->{creator} =~ qr/$acl/  # --> apply it
+                : 1
+        } @$result ];
+    }
+
+    return $result;
+}
+
+# Create SQL query parameters by processing API command parameters
+sub _make_query_params {
+    my ($self, $args, $columns) = @_;
 
     my $re_alpha_string = qr{ \A [ \w \- \. : \s ]* \z }xms;
 
     my $where = {};
     my $params = {
         where => $where,
-        columns => [ qw(
-            workflow_last_update
-            workflow.workflow_id
-            workflow_type
-            workflow_state
-            workflow_proc_state
-            workflow_wakeup_at
-            pki_realm
-        ) ],
+        columns => $columns,
     };
 
     ##! 16: 'Input args ' . Dumper $args
@@ -180,7 +206,7 @@ sub _search_query_params {
     # ACLs part 1: filter out workflow types with undefined ACLs (= no access)
     #
     my $user;
-    if ($check_acl) {
+    if ($args->check_acl) {
         $user = CTX('session')->data->user;
         my $role = CTX('session')->data->has_role ? CTX('session')->data->role : 'Anonymous';
 
@@ -209,6 +235,8 @@ sub _search_query_params {
             $add_creator = 1 if $creator_acl ne 'any'; # 'any': no restriction - user may see all workflows
         }
 
+        ##! 32: 'ACL check - workflow types and ACLs: ' . join(", ", map { sprintf "%s=%s", $_, $self->acl_by_wftype->{$_} } keys %{ $self->acl_by_wftype })
+
         # add the "creator" column
         push @{ $args->return_attributes }, 'creator' if $add_creator;
 
@@ -316,7 +344,7 @@ sub _search_query_params {
     #
     # ACLs part 2: filter by 'creator'
     #
-    if ($check_acl) {
+    if ($args->check_acl) {
         my @where_additions = ();
         for my $type (keys %{ $self->acl_by_wftype }) {
             my $acl = $self->acl_by_wftype->{$type};
@@ -356,26 +384,21 @@ sub _search_query_params {
     $where->{workflow_state} = $args->state if $args->has_state;
     $where->{workflow_proc_state} = $args->proc_state if $args->has_proc_state;
 
-    ##! 32: 'params: ' . Dumper $params
-    return $params;
-}
-
-sub _search_query_params_exclusive {
-    my ($self, $args) = @_;
-
-    my $params = {};
+    # process special API command parameters for non-counting search
+    if (not $self->count_only) {
+        if ($args->has_limit ) {
+            $params->{limit} = $args->limit;
+            $params->{offset} = $args->start if $args->has_start;
+        }
 
-    if ($args->has_limit ) {
-        $params->{limit} = $args->limit;
-        $params->{offset} = $args->start if $args->has_start;
+        # Custom ordering
+        my $desc = "-"; # not set or 0 means: DESCENDING, i.e. "-"
+        $desc = "" if $args->has_reverse and $args->reverse == 0;
+        my $order = $args->has_order ? $args->order : 'workflow_id';
+        $params->{order_by} = sprintf "%s%s", $desc, $order;
     }
 
-    # Custom ordering
-    my $desc = "-"; # not set or 0 means: DESCENDING, i.e. "-"
-    $desc = "" if $args->has_reverse and $args->reverse == 0;
-    my $order = $args->has_order ? $args->order : 'workflow_id';
-    $params->{order_by} = sprintf "%s%s", $desc, $order;
-
+    ##! 32: 'generated parameters: ' . Dumper $params
     return $params;
 }
 
diff --git a/qatest/backend/api2/43_workflow_acl.t b/qatest/backend/api2/43_workflow_acl.t
index 7b8b76f609..53bf5e3899 100644
--- a/qatest/backend/api2/43_workflow_acl.t
+++ b/qatest/backend/api2/43_workflow_acl.t
@@ -15,10 +15,11 @@ use Data::UUID;
 
 # Project modules
 use lib "$Bin/../../lib", "$Bin/../../../core/server/t/lib";
+#use OpenXPKI::Debug; BEGIN { $OpenXPKI::Debug::LEVEL{'OpenXPKI::Server::API2::Plugin::Workflow.*'} = 0b1111111 }
 use OpenXPKI::Test;
 use OpenXPKI::Test::CertHelper::Database;
 
-plan tests => 3;
+plan tests => 6;
 
 #
 # Setup test context
@@ -164,10 +165,18 @@ search_result { check_acl => 0, id => $all_ids },
         superhashof({ 'workflow_id' => $edel_regex->id }),
         superhashof({ 'workflow_id' => $edel_noaccess->id }),
     ),
-     "search_workflow_instances() - search without ACL check";
+     "search_workflow_instances() - no ACL check";
+
+# count workflows
+lives_and {
+    my $result = $oxitest->api2_command("search_workflow_instances_count" => { id => $all_ids });
+    is $result, 9;
+} "search_workflow_instances_count() - no ACL check";
 
 # search with ACL check
-search_result { check_acl => 1, id => $all_ids },
+my $query_with_acl_check = { check_acl => 1, id => $all_ids };
+
+search_result $query_with_acl_check,
     bag(
         superhashof({ 'workflow_id' => $alma_any->id }), # ACL 'any' - workflows by all users
         superhashof({ 'workflow_id' => $alma_self->id }), # ACL 'self' - own workflows
@@ -175,14 +184,26 @@ search_result { check_acl => 1, id => $all_ids },
         superhashof({ 'workflow_id' => $edel_others->id }), # ACL 'others' - workflow by other users
         superhashof({ 'workflow_id' => $edel_regex->id }), # ACL with regex - workflow by matching users
     ),
-     "search_workflow_instances() - search with ACL check";
+     "search_workflow_instances() - with ACL check";
+
+# count workflows
+lives_and {
+    my $result = $oxitest->api2_command("search_workflow_instances_count" => $query_with_acl_check);
+    is $result, 5;
+} "search_workflow_instances_count() - with ACL check";
 
+# search with ACL check but no access to ANY workflow
 CTX('session')->data->role('NonExistingRole');
 CTX('session')->data->user('fred');
 
-# search with ACL check but no access to ANY workflow
-search_result { check_acl => 1, id => $all_ids },
+search_result $query_with_acl_check,
     [],
-     "search_workflow_instances() - search with ACL check and no access to any workflow";
+     "search_workflow_instances() - with ACL check and no access to any workflow";
+
+# count workflows
+lives_and {
+    my $result = $oxitest->api2_command("search_workflow_instances_count" => $query_with_acl_check);
+    is $result, 0;
+} "search_workflow_instances_count() - with ACL check and no access to any workflow";
 
 1;

From f96b6030c48c0ddfec22068cba408a63c827bd48 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Tue, 28 Aug 2018 23:59:11 +0200
Subject: [PATCH 09/22] Prevent setting readonly attributes via constructor in
 O:Crypt::X509

---
 core/server/OpenXPKI/Crypt/X509.pm | 19 ++++++++++---------
 1 file changed, 10 insertions(+), 9 deletions(-)

diff --git a/core/server/OpenXPKI/Crypt/X509.pm b/core/server/OpenXPKI/Crypt/X509.pm
index 00f7c22208..8c959aee79 100644
--- a/core/server/OpenXPKI/Crypt/X509.pm
+++ b/core/server/OpenXPKI/Crypt/X509.pm
@@ -20,11 +20,12 @@ has data => (
 
 has pem => (
     is => 'ro',
-    required => 0,
+    init_arg => undef,
     isa => 'Str',
     lazy => 1,
     default => sub {
         my $self = shift;
+        # convert DER to PEM
         my $pem = encode_base64($self->data());
         $pem =~ s{\s}{}g;
         $pem =~ s{ (.{64}) }{$1\n}xmsg;
@@ -40,7 +41,7 @@ has _cert => (
 
 has cert_identifier => (
     is => 'rw',
-    required => 0,
+    init_arg => undef,
     isa => 'Str',
     reader => 'get_cert_identifier',
     lazy => 1,
@@ -55,7 +56,7 @@ has cert_identifier => (
 
 has subject => (
     is => 'ro',
-    required => 0,
+    init_arg => undef,
     isa => 'Str',
     reader => 'get_subject',
     lazy => 1,
@@ -67,7 +68,7 @@ has subject => (
 
 has issuer => (
     is => 'ro',
-    required => 0,
+    init_arg => undef,
     isa => 'Str',
     reader => 'get_issuer',
     lazy => 1,
@@ -79,7 +80,7 @@ has issuer => (
 
 has subject_key_id => (
     is => 'rw',
-    required => 0,
+    init_arg => undef,
     isa => 'Str',
     reader => 'get_subject_key_id',
     lazy => 1,
@@ -97,7 +98,7 @@ has subject_key_id => (
 
 has authority_key_id => (
     is => 'rw',
-    required => 0,
+    init_arg => undef,
     isa => 'Str',
     reader => 'get_authority_key_id',
     lazy => 1,
@@ -109,7 +110,7 @@ has authority_key_id => (
 
 has notbefore => (
     is => 'ro',
-    required => 0,
+    init_arg => undef,
     isa => 'Int',
     lazy => 1,
     default => sub {
@@ -120,7 +121,7 @@ has notbefore => (
 
 has notafter => (
     is => 'ro',
-    required => 0,
+    init_arg => undef,
     isa => 'Int',
     lazy => 1,
     default => sub {
@@ -131,7 +132,7 @@ has notafter => (
 
 has serial => (
     is => 'ro',
-    required => 0,
+    init_arg => undef,
     isa => 'Str',
     reader => 'get_serial',
     lazy => 1,

From 014d91228256461331f6ffd3e1514f9b65339d86 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Thu, 30 Aug 2018 22:07:15 +0200
Subject: [PATCH 10/22] Optimize evaluation of workflow ACLs of type regex

Only loop through results if there is at least one ACL of type regex.
This was Oliver's idea :-)
---
 .../Workflow/search_workflow_instances.pm     | 37 ++++++++++++++++---
 1 file changed, 31 insertions(+), 6 deletions(-)

diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
index 6c9af6fa8a..5e1de8f8c4 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
@@ -27,6 +27,7 @@ coerce 'ArrayOrAlphaPunct',
 has 'count_only' => (
     isa => 'Bool',
     is => 'rw',
+    init_arg => undef,
     default => 0,
 );
 
@@ -34,6 +35,7 @@ has 'count_only' => (
 has 'acl_by_wftype' => (
     isa => 'HashRef',
     is => 'rw',
+    init_arg => undef,
     default => sub { {} },
 );
 
@@ -177,12 +179,35 @@ sub _search {
 
     # ACLs part 3: apply ACL checks of type RegEx by filtering 'creator'
     if ($params->check_acl) {
-        $result = [ grep {
-            my $acl = $self->acl_by_wftype->{ $_->{workflow_type} };
-            $acl !~ /^(any|self|others)$/    # ACL of type regex?
-                ? $_->{creator} =~ qr/$acl/  # --> apply it
-                : 1
-        } @$result ];
+        my ($acl, $is_regex);
+
+        # check if there's any regex ACL
+        my $at_least_one_regex_acl = 0;
+
+        # map: workflow_type => is_regex_acl
+        my $acl_by_type = {
+            map {
+                $acl = $self->acl_by_wftype->{$_};
+                # ACL of type regex?
+                $is_regex = $acl !~ /^(any|self|others)$/;
+                $at_least_one_regex_acl |= $is_regex;
+                ( $_ => { acl => $acl, is_regex => $is_regex } )
+            }
+            keys %{ $self->acl_by_wftype }
+        };
+
+        if ($at_least_one_regex_acl) {
+            # apply regex checks
+            my $type;
+            $result = [ grep {
+                $type = $_->{workflow_type};
+                $acl = $acl_by_type->{$type}->{acl};
+                # if it's a regex...
+                $acl_by_type->{$type}->{is_regex}
+                    ? $_->{creator} =~ qr/$acl/  # ...apply it
+                    : 1
+            } @$result ];
+        }
     }
 
     return $result;

From ec31d34b0d937482079ae472b86d092bc4702238 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Thu, 30 Aug 2018 22:11:07 +0200
Subject: [PATCH 11/22] Avoid having different conditions that check
 'workflow_type'

---
 .../Plugin/Workflow/search_workflow_instances.pm     | 12 +++++++-----
 1 file changed, 7 insertions(+), 5 deletions(-)

diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
index 5e1de8f8c4..b99f53861d 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/search_workflow_instances.pm
@@ -246,7 +246,7 @@ sub _make_query_params {
         for my $type (@wf_types_to_check) {
             my $creator_acl = CTX('config')->get([ 'workflow', 'def', $type, 'acl', $role, 'creator' ]);
 
-            # do not query workflow types if there's no ACL (i.e. no access) for the current user's role
+            # do not query this workflow type if there's no ACL (i.e. no access) for the current user's role
             next unless $creator_acl;
 
             push @include_wf_types, $type;
@@ -257,7 +257,7 @@ sub _make_query_params {
             $self->acl_by_wftype->{$type} = $creator_acl;
 
             # add 'creator' column to be able to filter on it using WHERE later on
-            $add_creator = 1 if $creator_acl ne 'any'; # 'any': no restriction - user may see all workflows
+            $add_creator = 1 if $creator_acl ne 'any'; # any = no restriction: user may see all workflows
         }
 
         ##! 32: 'ACL check - workflow types and ACLs: ' . join(", ", map { sprintf "%s=%s", $_, $self->acl_by_wftype->{$_} } keys %{ $self->acl_by_wftype })
@@ -265,8 +265,7 @@ sub _make_query_params {
         # add the "creator" column
         push @{ $args->return_attributes }, 'creator' if $add_creator;
 
-        # filter by workflow type
-        $where->{workflow_type} = \@include_wf_types;
+        # we do not add $where->{workflow_type} here, it's done later on in more detail
     }
     else {
         $where->{workflow_type} = $args->type if $args->has_type;
@@ -370,7 +369,10 @@ sub _make_query_params {
     # ACLs part 2: filter by 'creator'
     #
     if ($args->check_acl) {
-        my @where_additions = ();
+        my @where_additions = ( \"0 = 1" );
+        # WHERE ( 0 = 1 OR ... ) is a trick to make sure that NO rows are
+        # returned (instead of ALL rows) if $self->acl_by_wftype is empty and
+        # thus no other conditions are added.
         for my $type (keys %{ $self->acl_by_wftype }) {
             my $acl = $self->acl_by_wftype->{$type};
             my $creator_col = $attr_value_colspec{'creator'};

From a259fc7b0845f74b4f7b1a5f5243f0ffd20ea6f6 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Thu, 30 Aug 2018 22:40:04 +0200
Subject: [PATCH 12/22] Delete workflows after tests; restrict all tests to
 just created wf

---
 qatest/backend/api2/40_workflow.t        | 70 +++++++++++++-----------
 qatest/backend/api2/41_workflow_wakeup.t | 18 ++++--
 qatest/backend/api2/42_workflow_resume.t |  8 +++
 qatest/backend/api2/43_workflow_acl.t    |  5 ++
 4 files changed, 65 insertions(+), 36 deletions(-)

diff --git a/qatest/backend/api2/40_workflow.t b/qatest/backend/api2/40_workflow.t
index 10b755d10b..e12c07d6e1 100644
--- a/qatest/backend/api2/40_workflow.t
+++ b/qatest/backend/api2/40_workflow.t
@@ -11,6 +11,7 @@ use Test::More;
 use Test::Deep;
 use Test::Exception;
 use DateTime;
+use Data::UUID;
 
 # Project modules
 use lib "$Bin/../../lib", "$Bin/../../../core/server/t/lib";
@@ -137,14 +138,16 @@ sub workflow_def {
 my $wf_def_noinit = workflow_def("wf_type_no_initial_action");
 $wf_def_noinit->{state}->{INITIAL} = {};
 
+my $uuid = Data::UUID->new->create_str; # so we don't see workflows from previous test runs
+
 my $oxitest = OpenXPKI::Test->new(
     with => [ qw( TestRealms Workflows ) ],
     add_config => {
-        "realm.alpha.workflow.def.wf_type_1" => workflow_def("wf_type_1"),
-        "realm.alpha.workflow.def.wf_type_2" => workflow_def("wf_type_2"),
-        "realm.alpha.workflow.def.wf_type_3_unused" => workflow_def("wf_type_3_unused"),
-        "realm.alpha.workflow.def.wf_type_no_initial_action" => $wf_def_noinit,
-        "realm.beta.workflow.def.wf_type_4" => workflow_def("wf_type_4"),
+        "realm.alpha.workflow.def.wf_type_1_$uuid" => workflow_def("wf_type_1"),
+        "realm.alpha.workflow.def.wf_type_2_$uuid" => workflow_def("wf_type_2"),
+        "realm.alpha.workflow.def.wf_type_3_unused_$uuid" => workflow_def("wf_type_3_unused"),
+        "realm.alpha.workflow.def.wf_type_no_initial_action_$uuid" => $wf_def_noinit,
+        "realm.beta.workflow.def.wf_type_4_$uuid" => workflow_def("wf_type_4"),
     },
     enable_workflow_log => 1, # while testing we do not log to database by default
 );
@@ -163,23 +166,23 @@ CTX('session')->data->role('User');
 CTX('session')->data->pki_realm("alpha");
 
 CTX('session')->data->user('wilhelm');
-my $wf_t1_sync =   $oxitest->create_workflow("wf_type_1", $params);
-my $wf_t1_async1 = $oxitest->create_workflow("wf_type_1", $params);
-my $wf_t1_async2 = $oxitest->create_workflow("wf_type_1", $params);
+my $wf_t1_sync =   $oxitest->create_workflow("wf_type_1_$uuid", $params);
+my $wf_t1_async1 = $oxitest->create_workflow("wf_type_1_$uuid", $params);
+my $wf_t1_async2 = $oxitest->create_workflow("wf_type_1_$uuid", $params);
 
 CTX('session')->data->user('franz');
-my $wf_t1_fail = $oxitest->create_workflow("wf_type_1", $params);
+my $wf_t1_fail = $oxitest->create_workflow("wf_type_1_$uuid", $params);
 
 CTX('session')->data->user('wilhelm');
-my $wf_t2 =   $oxitest->create_workflow("wf_type_2", $params);
+my $wf_t2 =   $oxitest->create_workflow("wf_type_2_$uuid", $params);
 
 CTX('session')->data->pki_realm("beta");
-my $wf_t4 =   $oxitest->create_workflow("wf_type_4", $params);
+my $wf_t4 =   $oxitest->create_workflow("wf_type_4_$uuid", $params);
 
 throws_ok {
     CTX('session')->data->pki_realm("alpha");
     $oxitest->api2_command("create_workflow_instance" => {
-        workflow => "wf_type_no_initial_action",
+        workflow => "wf_type_no_initial_action_$uuid",
         params => {
             message => "Lucy in the sky with diamonds",
             link => "http://www.denic.de",
@@ -199,8 +202,8 @@ CTX('session')->data->pki_realm('alpha');
 lives_and {
     my $result = $oxitest->api2_command("get_workflow_instance_types");
     cmp_deeply $result, superhashof({
-        wf_type_1 => superhashof({ label => "wf_type_1" }),
-        wf_type_2 => superhashof({ label => "wf_type_2" }),
+        $wf_t1_sync->type => superhashof({ label => "wf_type_1" }),
+        $wf_t2->type      => superhashof({ label => "wf_type_2" }),
     }), "get_workflow_instance_types()";
 }
 
@@ -209,7 +212,7 @@ lives_and {
 #
 lives_and {
     my $result = $oxitest->api2_command("get_workflow_type_for_id" => { id => $wf_t1_sync->id });
-    is $result, "wf_type_1", "get_workflow_type_for_id()";
+    is $result, $wf_t1_sync->type, "get_workflow_type_for_id()";
 }
 
 dies_ok {
@@ -292,9 +295,9 @@ lives_and {
 lives_and {
     my $result = $oxitest->api2_command("list_workflow_titles");
     cmp_deeply $result, superhashof({
-        'wf_type_1'         => { label => ignore(), description => ignore(), },
-        'wf_type_2'         => { label => ignore(), description => ignore(), },
-        'wf_type_3_unused'  => { label => ignore(), description => ignore(), },
+        $wf_t1_sync->type         => { label => ignore(), description => ignore(), },
+        $wf_t2->type              => { label => ignore(), description => ignore(), },
+        "wf_type_3_unused_$uuid"  => { label => ignore(), description => ignore(), },
     });
 } "list_workflow_titles()";
 
@@ -320,7 +323,7 @@ lives_and {
             proc_state => 'manual',
             reap_at => re(qr/^\d+$/),
             state => 'PERSIST',
-            type => 'wf_type_2',
+            type => $wf_t2->type,
             wake_up_at => ignore(),
             description => ignore(),
             label => 'wf_type_2',
@@ -386,7 +389,7 @@ lives_and {
         workflow => superhashof({
             id => re(qr/^\d+$/),
             state => 'INITIAL',
-            type => 'wf_type_2',
+            type => $wf_t2->type,
             description => ignore(),
             label => 'wf_type_2',
         }),
@@ -459,7 +462,7 @@ lives_and {
 #
 lives_and {
     my $result = $oxitest->api2_command("get_workflow_activities" => {
-        workflow => "wf_type_2",
+        workflow => $wf_t2->type,
         id => $wf_t2->id,
     });
     cmp_deeply $result, [
@@ -472,7 +475,7 @@ lives_and {
 #
 lives_and {
     my $result = $oxitest->api2_command("get_workflow_activities_params" => {
-        workflow => "wf_type_2",
+        workflow => $wf_t2->type,
         id => $wf_t2->id,
     });
     cmp_deeply $result, [
@@ -524,18 +527,18 @@ search_result { id => [ $wf_t1_sync->id, $wf_t1_fail->id, $wf_t2->id ] },
 
 # TODO Tests: Remove superbagof() constructs below once we have a clean test database
 
-search_result { attribute => [ { KEY => "creator", VALUE => "franz" } ] },
+search_result { type => $wf_t1_fail->type, attribute => [ { KEY => "creator", VALUE => "franz" } ] },
     all(
-        superbagof($wf_t1_fail_data),                                                  # expected record
+        superbagof($wf_t1_fail_data),                                       # expected record
         array_each(superhashof({ 'workflow_type' => $wf_t1_fail->type })),  # make sure we got no other types (=other creators)
     ),
     "search_workflow_instances() - search by ATTRIBUTE";
 
-search_result { type => [ "wf_type_1", "wf_type_2" ] },
+search_result { type => [ $wf_t1_sync->type, $wf_t2->type ] },
     superbagof($wf_t1_sync_data, $wf_t1_fail_data, $wf_t2_data),
     "search_workflow_instances() - search by TYPE (ArrayRef)";
 
-search_result { type => "wf_type_2" },
+search_result { type => $wf_t2->type },
     all(
         superbagof($wf_t2_data),                                                    # expected record
         array_each(superhashof({ 'workflow_type' => $wf_t2->type })),    # make sure we got no other types
@@ -590,15 +593,15 @@ lives_and {
 
 # Check custom order by TYPE
 lives_and {
-    my $result = $oxitest->api2_command("search_workflow_instances" => { pki_realm => "alpha", order => "WORKFLOW_TYPE" });
-    my $prev_type;
+    my $result = $oxitest->api2_command("search_workflow_instances" => { pki_realm => "alpha", order => "workflow_proc_state" });
+    my $prev_val;
     my $sorting_ok = 1;
     for (@{$result}) {
-        $sorting_ok = 0 if $prev_type and ($_->{'workflow_type'} cmp $prev_type) > 0;
-        $prev_type = $_->{'workflow_type'};
+        $sorting_ok = 0 if $prev_val and ($_->{'workflow_proc_state'} cmp $prev_val) > 0;
+        $prev_val = $_->{'workflow_proc_state'};
     }
     is $sorting_ok, 1;
-} "search_workflow_instances() - result ordering by custom TYPE";
+} "search_workflow_instances() - result ordering by custom column";
 
 search_result
     {
@@ -634,4 +637,9 @@ lives_and {
 
 } "search_workflow_instances_count()";
 
+# delete test workflows
+$oxitest->dbi->start_txn;
+$oxitest->dbi->delete(from => 'workflow', where => { workflow_type => [ -like => "%$uuid" ] } );
+$oxitest->dbi->commit;
+
 1;
diff --git a/qatest/backend/api2/41_workflow_wakeup.t b/qatest/backend/api2/41_workflow_wakeup.t
index 93b48b784a..23160a8684 100644
--- a/qatest/backend/api2/41_workflow_wakeup.t
+++ b/qatest/backend/api2/41_workflow_wakeup.t
@@ -8,6 +8,7 @@ use FindBin qw( $Bin );
 
 # CPAN modules
 use Test::More;
+use Data::UUID;
 
 # Project modules
 use lib "$Bin/../../lib", "$Bin/../../../core/server/t/lib";
@@ -55,10 +56,12 @@ my $workflow_def = {
     },
 };
 
+my $uuid = Data::UUID->new->create_str; # so we don't see workflows from previous test runs
+
 my $oxitest = OpenXPKI::Test->new(
     with => [ qw( TestRealms Workflows ) ],
     add_config => {
-        "realm.alpha.workflow.def.wf_with_a_rest" => $workflow_def,
+        "realm.alpha.workflow.def.wf_with_a_rest_$uuid" => $workflow_def,
     },
     #log_level => "debug",
 );
@@ -69,16 +72,16 @@ my $oxitest = OpenXPKI::Test->new(
 CTX('session')->data->pki_realm('alpha');
 CTX('session')->data->role('User');
 CTX('session')->data->user('wilhelm');
-my $wf = $oxitest->create_workflow("wf_with_a_rest");
+my $wf = $oxitest->create_workflow("wf_with_a_rest_$uuid");
 $wf->state_is("RESTING");
 
-my $info = $oxitest->api2_command("wakeup_workflow" => { id => $wf->id, type => "wf_with_a_rest" });
+my $info = $oxitest->api2_command("wakeup_workflow" => { id => $wf->id, type => "wf_with_a_rest_$uuid" });
 is $info->{workflow}->{state}, "SUCCESS", "synchronous wakeup successful";
 
 #
 # asynchronous wakeup ('watch'), but watching and waiting
 #
-$wf = $oxitest->create_workflow("wf_with_a_rest");
+$wf = $oxitest->create_workflow("wf_with_a_rest_$uuid");
 $wf->state_is("RESTING");
 
 $info = $oxitest->api2_command("wakeup_workflow" => { id => $wf->id, async => 1, wait => 1 });
@@ -87,7 +90,7 @@ is $info->{workflow}->{state}, "SUCCESS", "asynchronous wakeup successful (block
 #
 # asynchronous wakeup ('fork')
 #
-$wf = $oxitest->create_workflow("wf_with_a_rest");
+$wf = $oxitest->create_workflow("wf_with_a_rest_$uuid");
 $wf->state_is("RESTING");
 
 $info = $oxitest->api2_command("wakeup_workflow" => { id => $wf->id, async => 1 });
@@ -100,4 +103,9 @@ while (time < $timeout) {
 }
 is $info->{workflow}->{state}, "SUCCESS", "asynchronous wakeup successful (nonblocking mode)";
 
+# delete test workflows
+$oxitest->dbi->start_txn;
+$oxitest->dbi->delete(from => 'workflow', where => { workflow_type => [ -like => "%$uuid" ] } );
+$oxitest->dbi->commit;
+
 1;
diff --git a/qatest/backend/api2/42_workflow_resume.t b/qatest/backend/api2/42_workflow_resume.t
index 9bd5163cb6..ec627ad7c9 100644
--- a/qatest/backend/api2/42_workflow_resume.t
+++ b/qatest/backend/api2/42_workflow_resume.t
@@ -8,6 +8,7 @@ use FindBin qw( $Bin );
 
 # CPAN modules
 use Test::More;
+use Data::UUID;
 
 # Project modules
 use lib $Bin, "$Bin/../../lib", "$Bin/../../../core/server/t/lib";
@@ -53,6 +54,8 @@ my $workflow_def = {
     },
 };
 
+my $uuid = Data::UUID->new->create_str; # so we don't see workflows from previous test runs
+
 my $oxitest = OpenXPKI::Test->new(
     with => [ qw( TestRealms Workflows ) ],
     add_config => {
@@ -90,4 +93,9 @@ my $info = $oxitest->api2_command("resume_workflow" => { id => $wf->id, async =>
 is $info->{workflow}->{proc_state}, "finished", "workflow is finished";
 is $info->{workflow}->{state}, "SUCCESS", "workflow is in state SUCCESS";
 
+# delete test workflows
+$oxitest->dbi->start_txn;
+$oxitest->dbi->delete(from => 'workflow', where => { workflow_type => "wf_that_explodes" } );
+$oxitest->dbi->commit;
+
 1;
diff --git a/qatest/backend/api2/43_workflow_acl.t b/qatest/backend/api2/43_workflow_acl.t
index 53bf5e3899..fa923b2270 100644
--- a/qatest/backend/api2/43_workflow_acl.t
+++ b/qatest/backend/api2/43_workflow_acl.t
@@ -206,4 +206,9 @@ lives_and {
     is $result, 0;
 } "search_workflow_instances_count() - with ACL check and no access to any workflow";
 
+# delete test workflows
+$oxitest->dbi->start_txn;
+$oxitest->dbi->delete(from => 'workflow', where => { workflow_type => [ -like => "%$uuid" ] } );
+$oxitest->dbi->commit;
+
 1;

From 5899d4bdaf3ac1b386079929b8d113411e4796a7 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 3 Sep 2018 14:39:33 +0200
Subject: [PATCH 13/22] Remove if-branch that never gets executed

Commit 80dc79d made this if-branch unreachable.
---
 core/server/OpenXPKI/Debug.pm | 8 --------
 1 file changed, 8 deletions(-)

diff --git a/core/server/OpenXPKI/Debug.pm b/core/server/OpenXPKI/Debug.pm
index 3d368902a0..5daec8996a 100644
--- a/core/server/OpenXPKI/Debug.pm
+++ b/core/server/OpenXPKI/Debug.pm
@@ -36,14 +36,6 @@ sub import
         $module = (caller(0))[0];
     }
 
-     #foreach my $key (keys %LEVEL)
-     #{
-     #   print STDERR "Debugging module(s) '$key' with level $LEVEL{$key}.\n";
-     #}
-
-    ## import only be called to specify the different levels
-    return if (not defined $module);
-
     if ($USE_COLOR) {
         use Term::ANSIColor;
     }

From 685027082846c9ae435d0d82adeff06b9204a94e Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 3 Sep 2018 14:44:01 +0200
Subject: [PATCH 14/22] Allow for specifying debug level as bitmask or maximum
 level

---
 core/server/OpenXPKI/Control.pm |  34 +++++---
 core/server/OpenXPKI/Debug.pm   | 147 +++++++++++++++++++-------------
 core/server/bin/openxpkictl     |  69 ++++++++++-----
 3 files changed, 155 insertions(+), 95 deletions(-)

diff --git a/core/server/OpenXPKI/Control.pm b/core/server/OpenXPKI/Control.pm
index 38bea6d2a4..93f18586a0 100644
--- a/core/server/OpenXPKI/Control.pm
+++ b/core/server/OpenXPKI/Control.pm
@@ -72,8 +72,11 @@ Weather to start the daemon in foreground (implies restart)
 =item RESTART (0|1)
 Weather to restart a running server
 
-=item DEBUG
-single scalar as global debug level or hashref of module => level
+=item DEBUG_LEVEL
+hashref: module => level
+
+=item DEBUG_BITMASK
+hashref: module => bitmask
 
 =back
 
@@ -86,28 +89,31 @@ sub start {
     my $pid        = $args->{PID};
     my $foreground = $args->{FOREGROUND};
     my $restart = $args->{RESTART} || $args->{FOREGROUND};
-    my $debug      = $args->{DEBUG} || 0;
+    my $debug_level = $args->{DEBUG_LEVEL} || 0;
+    my $debug_bitmask = $args->{DEBUG_BITMASK} || 0;
 
 
     # We must set the debug options before loading any OXI classes
-    # Parsing any class before the debug level is set, will exlude the class
+    # Parsing any class before the debug level is set will exlude the class
     # from debugging!
     #
-    # Set debug options - DEBUG is hash with the module name (wildcard)
+    # DEBUG_LEVEL is a hash with the module name (or regex)
     # as key and the level as value or just an integer for the global level
-    if (ref $debug eq '') {
-        if ($debug > 0) {
-            $OpenXPKI::Debug::LEVEL{'.*'} = $debug;
-        }
-    } elsif(ref $debug eq 'HASH') {
-        foreach my $module (keys %{$debug}) {
-            my $level = $debug->{$module};
-            print STDERR "Debug level for module '$module': $level\n";
+    if (ref $debug_level eq 'HASH') {
+        foreach my $module (keys %{$debug_level}) {
+            my $level = $debug_level->{$module};
             $OpenXPKI::Debug::LEVEL{$module} = $level;
         }
-        #print Dumper %OpenXPKI::Debug::LEVEL;
     }
 
+    # DEBUG_BITMASK is a hash with the module name (or regex)
+    # as key and the bitmask as value or just an integer for the global bitmask
+    if (ref $debug_bitmask eq 'HASH') {
+        foreach my $module (keys %{$debug_bitmask}) {
+            my $bitmask = $debug_bitmask->{$module};
+            $OpenXPKI::Debug::BITMASK{$module} = $bitmask;
+        }
+    }
 
     # Load the required locations from the config
     my $config = OpenXPKI::Control::__probe_config( $args );
diff --git a/core/server/OpenXPKI/Debug.pm b/core/server/OpenXPKI/Debug.pm
index 5daec8996a..5d7b983476 100644
--- a/core/server/OpenXPKI/Debug.pm
+++ b/core/server/OpenXPKI/Debug.pm
@@ -7,9 +7,10 @@
 
 ## BIG FAT WARNING: This class works using so called compile time filters
 # The decission weather to apply debugging to a class or not is made based
-# on the %FILTER hash at the time the module is included for the first time
-# In turn, if you load a module before you set up the %FILTER hash, the
-# module will not be decorated with debug output!
+# on the %BITMASK and %LEVEL hashes at the time the module is included for
+# the first time.
+# In turn, if you load a module before you set up the %BITMASK / %LEVEL hashes,
+# the module will not be decorated with debug output!
 # The fastest way to ruin the story is "use" in the head of your start scripts.
 
 use strict;
@@ -23,12 +24,12 @@ use Filter::Util::Call;
 use Data::Dumper;
 
 our %LEVEL;
+our %BITMASK;
 our $USE_COLOR = 0;
 
-sub import
-{
+sub import {
     my($self,$module) = @_ ;
-    if (! defined $module) {
+    if (not defined $module) {
         # if the module name was not passed explicitly using
         # use OpenXPKI::Debug 'ModuleName',
         # we just assume that the module is the caller of the
@@ -39,27 +40,40 @@ sub import
     if ($USE_COLOR) {
         use Term::ANSIColor;
     }
+
     ## only for debugging of this module
     #print STDERR "OpenXPKI::Debug: Checking module $module ...\n";
-    #print STDERR Dumper %LEVEL;
-
-    ## perhaps a regex was used in the LEVEL spec
-    if (not exists $LEVEL{$module})
-    {
-        foreach my $regex (keys %LEVEL)
-        {
-            #print STDERR "Regex $regex ~ $module\n";
-           if ($module =~ /^$regex$/) {
-              print STDERR "Debugging module(s) '$module' with level $LEVEL{$regex}.\n";
-              $LEVEL{$module} = $LEVEL{$regex};
-           }
+    #print STDERR Dumper %BITMASK;
+
+    if (not exists $BITMASK{$module}) {
+        if (exists $LEVEL{$module}) {
+            $BITMASK{$module} = __level_to_bitmask($LEVEL{$module});
+        }
+        else {
+            ## try to interpret BITMASK specs as regex
+            for my $regex (keys %BITMASK) {
+               if ($module =~ /^$regex$/) {
+                  $BITMASK{$module} = $BITMASK{$regex};
+                  last;
+               }
+            }
+            ## try to interpret LEVEL specs as regex
+            if (not exists $BITMASK{$module}) {
+                for my $regex (keys %LEVEL) {
+                   if ($module =~ /^$regex$/) {
+                      $BITMASK{$module} = __level_to_bitmask($LEVEL{$regex});
+                      last;
+                   }
+                }
+            }
         }
     }
 
     ## return if the module is not in debug mode
     ## debug messages no longer influence the performance now
-    return if (not exists $LEVEL{$module} or
-               $LEVEL{$module} < 1);
+    return unless $BITMASK{$module}; # not defined or 0
+
+    printf STDERR "Debugging module '%s' with bitmask %b.\n", $module, $BITMASK{$module};
 
     #print STDERR "Add Debug in $module\n";
     ## activate debugging for this module
@@ -67,23 +81,26 @@ sub import
     filter_add($self) ;
 }
 
-sub filter
-{
+sub __level_to_bitmask {
+    my ($level) = @_;
+    # get the exponent of the last power of 2
+    my $log_base_2 = floor( log($level) / log(2) );
+    # set all bits up to that power of 2
+    return 2 ** ($log_base_2 + 1) - 1;
+}
+
+sub filter {
     my $self = shift;
     my($status) ;
 
-    if (($status = filter_read()) > 0)
-    {
-        if ($_ =~ /^\s*##!/)
-        {
+    if (($status = filter_read()) > 0) {
+        if ($_ =~ /^\s*##!/) {
             my $msg = $_;
-            if ($msg =~ s/^\s*##!\s*(\d+)\s*([\w\s]*):\s*//)
-            {
+            if ($msg =~ s/^\s*##!\s*(\d+)\s*([\w\s]*):\s*//) {
                 ## higher levels mean more noise
                 my $level = $1;
                 my $color = $2;
-                if ($1 & $LEVEL{$self->{MODULE}})
-                {
+                if ($1 & $BITMASK{$self->{MODULE}}) {
                     $msg =~ s/\n//s;
                     ##--------------------------------------------------##
                     # HERE BE DRAGONS ... HERE BE DRAGONS ...
@@ -121,7 +138,7 @@ sub filter
             MESSAGE    => sub { $msg },
             LINE       => \$line,
             SUBROUTINE => \$subroutine,
-            LEVEL      => q{$level},
+            BITMASK    => q{$level},
             COLOR      => q{$color}
         });
     };
@@ -149,8 +166,7 @@ XEOF
     $status ;
 }
 
-sub debug
-{
+sub debug {
     my $arg_ref    = shift;
     my $msg        = $arg_ref->{MESSAGE};
     if (ref $msg ne 'CODE') {
@@ -166,7 +182,7 @@ sub debug
     $msg = &$msg();
     my $line       = $arg_ref->{LINE};
     my $subroutine = $arg_ref->{SUBROUTINE};
-    my $level      = $arg_ref->{LEVEL} || "0";
+    my $bitmask    = $arg_ref->{BITMASK} || "0";
     my $color      = $arg_ref->{COLOR};
 
     $msg = OpenXPKI::Debug::__censor_msg($msg);
@@ -185,7 +201,7 @@ sub debug
         my ($seconds, $microseconds) = Time::HiRes::gettimeofday();
         $timestamp .= '.' . sprintf("%06d", $microseconds);
     };
-    my $output = "$timestamp DEBUG:$level PID:$PROCESS_ID $msg";
+    my $output = "$timestamp DEBUG:$bitmask PID:$PROCESS_ID $msg";
     if ($USE_COLOR && $color) {
         eval {
             # try to color the output
@@ -236,30 +252,31 @@ your code then you have to do the following.
 my $variable = "some critical content";
 ##! 2: $variable
 
-A debug statement must be started with "\s*##!". The next number
-specifies the debug level. Higher levels mean more messages. If the
-message is important then you should choose a small number bigger
+A debug statement must be started with "\s*##!". The next number specifies
+the debug level. It has to be a power of 2. Higher levels mean more messages.
+If the message is important then you should choose a small number bigger
 than zero. The colon is a separator. After the colon the code follows
 which will be executed.
 
-If we use debug level 1 for this module then the above message will
-not be displayed. If you use 3 then the above message will be displayed.
+If later on you set debug level 1 for this module then the above message will
+not be displayed. If you set level 4 the message will be displayed.
 
 =item 2. Use your module:
 
-Add to the startup script the following lines:
+Add the following lines to the startup script:
 
-use OpenXPKI::Debug;
-$OpenXPKI::Debug::LEVEL{'MyM.*'} = 100;
+    use OpenXPKI::Debug;
+    $OpenXPKI::Debug::BITMASK{'MyM.*'} = 0b1010; # BITMASK: show level 2 and 8 messages
+    # $OpenXPKI::Debug::LEVEL{'MyM.*'} = 4;      # LEVEL: show messages up to level 4
 
-require MyModule; ## or require a module which use my Module
+    require MyModule; ## or require a module which use my Module
 
-In practice you will only have to add the LEVEL line because
-require is used to load the server which does the rest for you.
+In practice you will only have to add the BITMASK or LEVEL line because
+C<require> is used to load the server which does the rest for you.
 
-Please remember to not implement a use statement before you run
-require after you specified the debug level. This debug module
-manipulates the code parsing of Perl!!!
+Please remember to not implement a C<use> statement before you run
+C<require> after you specified the debug level. This debug module
+manipulates the code parsing of Perl!
 
 =back
 
@@ -267,26 +284,36 @@ manipulates the code parsing of Perl!!!
 
 =head2 import
 
-This function is executed if you call use or require for a module.
-It checks if debugging is activated for this module and decides
-whether a source filter has to be loaded or not.
+Executed if you C<use> or C<require> this module in another module. Checks if
+debugging is activated for the calling module and decides whether a source
+filter has to be applied or not.
 
 =head2 filter
 
-is the function which implements the source filtering for the debugging.
-The function will only be used if the debugging was activated by the
-import function. Please see Filter::Util::Call for more details.
+Implements the source filtering.
+
+This function will only be used if the debugging was activated by the
+import function. Please see L<Filter::Util::Call> for more details.
 
 =head2 debug
 
-This function builds the debug message. It outputs such things like
-the debug level, the module name and the source code line.
+Build the debug message. Also output debug level, module name and source code
+line.
 
 =head2 __censor_msg
 
-This method is used to censor debug messages that potentially contain
-confidential information such as passwords or private keys.
+Censor debug messages that potentially contain confidential information such as
+passwords or private keys.
+
+=head2 __level_to_bitmask
+
+Converts a maximum debug level to a bitmask. The bitmask will be the minimum
+value that includes the given level and where all bits are set.
+
+    7  => 111  (7)
+    8  => 1111 (15)
+    12 => 1111 (15)
 
 =head1 See also
 
-Filter::Util::Call
+L<Filter::Util::Call>
diff --git a/core/server/bin/openxpkictl b/core/server/bin/openxpkictl
index 73f459dd2d..8e032a5af3 100755
--- a/core/server/bin/openxpkictl
+++ b/core/server/bin/openxpkictl
@@ -80,19 +80,31 @@ if ($cmd eq 'status') {
     }
 
     if (defined $params{debug}) {
-
         @{$params{debug}} = split(m{,}, join(',', @{$params{debug}}));
+        $args->{DEBUG_LEVEL} = {};
+        $args->{DEBUG_BITMASK} = {};
+
+        for my $param (@{ $params{debug} }) {
+            my ($module, $op, $level) = ($param =~ m{ \A ((?!\d).+?)?([:=])?((0b)?\d+)? \z }xms);
+
+            # default values if not specified
+            $level //= 1;
+            $op = ':' if (not $module and not $op); # if only number was given: interpret as level
+            $module //= '.*';
 
-        $args->{DEBUG} = {};
-        foreach my $param (@{$params{debug}}) {
-            my ($module, $level) = ($param =~ m{ \A (.*?):?(\d*) \z }xms);
-            if ($level eq '') {
-                $level = 1;
+            # convert binary bitmask/level specifications
+            if ($level =~ /^0b(.*)/) {
+                $level = unpack("N", pack("B32", substr("0"x32 . $1, -32)));
             }
-            if ($module eq '') {
-                $args->{DEBUG} = $level;
-            } else {
-                $args->{DEBUG}->{$module} = $level;
+
+            # operator ":" - a maximum level
+            if ($op and $op eq ":") {
+                $args->{DEBUG_LEVEL}->{$module} = $level;
+            }
+            # operator "=" - a bitmask
+            else {
+                # also assume it's a bitmask if no operator and no number were given
+                $args->{DEBUG_BITMASK}->{$module} = $level;
             }
         }
     }
@@ -125,17 +137,32 @@ openxpkictl - start/stop script for OpenXPKI server
 openxpkictl [options] COMMAND
 
  Options:
-   --help                brief help message
-   --man                 full documentation
-   --config PATH         use configuration from path (base of yaml tree)
-   --instance|i NAME     Shortcut to set the config path to
-                         /etc/openxpki/<instance>/config.d
-   --debug  MODULE:LEVEL set MODULE debug level to LEVEL
-                         (positive integer value).
-                         MODULE defaults to '.*'
-                         LEVEL defaults to 1
-   --foreground          Uses a non-forking server. This is only
-                         useful for debugging or profiling.
+   --help
+        Brief help message
+
+   --man
+        Full documentation
+
+   --config PATH
+        Use configuration from path (base of yaml tree)
+
+   --instance|i NAME
+        Shortcut to set the config path to /etc/openxpki/<instance>/config.d
+
+   --debug [MODULE:]LEVEL
+        Show debug messages of MODULE whose level are lower or equal to the
+        given LEVEL.
+        LEVEL can be specified as a decadic or binary number (e.g. 5 or 0b101).
+        If MODULE is omitted the given LEVEL will be set for all modules.
+
+   --debug MODULE[=BITMASK]
+        Show debug messages of MODULE whose level fits into the given BITMASK
+        (i.e. "level AND BITMASK == level").
+        BITMASK can be specified as a decadic or binary number (e.g. 5 or
+        0b101). If not given BITMASK defaults to 1.
+
+   --foreground
+        Use a non-forking server: only useful for debugging or profiling.
 
  Commands:
    start            Start OpenXPKI daemon

From 8a676f7c406198097a973f35788e52c7f0c61719 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 3 Sep 2018 15:25:43 +0200
Subject: [PATCH 15/22] Fix DEBUG_BITMASK argument to
 OpenXPKI::Control::start() in test scripts

---
 core/server/t/60_workflow/09_deploy_and_start_testserver.t | 6 +++---
 core/server/t/60_workflow/start.pl                         | 2 +-
 2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/core/server/t/60_workflow/09_deploy_and_start_testserver.t b/core/server/t/60_workflow/09_deploy_and_start_testserver.t
index ebaeaf5550..0f52711d30 100644
--- a/core/server/t/60_workflow/09_deploy_and_start_testserver.t
+++ b/core/server/t/60_workflow/09_deploy_and_start_testserver.t
@@ -17,12 +17,12 @@ TODO: {
 
 diag("Deploying OpenXPKI test instance\n");
 
-# The server tests relys on the ca and database which is setup 
+# The server tests relys on the ca and database which is setup
 # in the earlier tests
 
 `mkdir -p t/var/openxpki/session/`;
 
-my $socketfile = 't/var/openxpki/openxpki.socket'; 
+my $socketfile = 't/var/openxpki/openxpki.socket';
 my $pidfile = 't/var/openxpki/openxpkid.pid';
 
 -e $socketfile && die "Socketfile exists - please stop server/remove socket";
@@ -34,7 +34,7 @@ use OpenXPKI::Server;
 $ENV{OPENXPKI_CONF_DB} = 't/config.git';
 
 # FIXME - prove becomes defunct - seems to be some issue with stdout/stderr
-#ok!(OpenXPKI::Control::start({ SILENT => 0, DEBUG =>  0 }));
+#ok!(OpenXPKI::Control::start({ SILENT => 0, DEBUG_BITMASK =>  0 }));
 ok(!system('OPENXPKI_CONF_DB="t/config.git" perl t/60_workflow/start.pl 2>/dev/null 1>/dev/null'));
 
 # wait for server startup
diff --git a/core/server/t/60_workflow/start.pl b/core/server/t/60_workflow/start.pl
index 490282ab4b..668005ea58 100755
--- a/core/server/t/60_workflow/start.pl
+++ b/core/server/t/60_workflow/start.pl
@@ -4,5 +4,5 @@
 use English;
 use OpenXPKI::Control;
 
-exit OpenXPKI::Control::start({ SILENT => 1, DEBUG =>  0 });
+exit OpenXPKI::Control::start({ SILENT => 1, DEBUG_BITMASK =>  0 });
 

From 89e9d460ae16061f03de837e8f22233089cefb49 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 3 Sep 2018 20:16:26 +0200
Subject: [PATCH 16/22] Fix debug message

---
 core/server/OpenXPKI/Server/Workflow/Activity.pm | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/core/server/OpenXPKI/Server/Workflow/Activity.pm b/core/server/OpenXPKI/Server/Workflow/Activity.pm
index c9cceba25b..82ed0c975b 100644
--- a/core/server/OpenXPKI/Server/Workflow/Activity.pm
+++ b/core/server/OpenXPKI/Server/Workflow/Activity.pm
@@ -214,7 +214,7 @@ sub get_reap_at_interval{
         ##! 16: 'manual set: '.$self->{REAP_AT_INTERVAL}
         return $self->{REAP_AT_INTERVAL};
     }
-    ##! 16: nothing defined, return default'
+    ##! 16: 'nothing defined, return default'
     return "+0000000005";
 }
 
@@ -250,7 +250,7 @@ sub get_retry_interval {
         return $self->param('retry_interval');
     }
     # TODO default setting?
-    ##! 16: nothing defined, return default'
+    ##! 16: 'nothing defined, return default'
     return "+0000000005";
 }
 

From fe09eb9100e9073465b708c0edaa908d473c05fa Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 3 Sep 2018 22:30:16 +0200
Subject: [PATCH 17/22] Add/edit debug messages

---
 .../Server/API2/Plugin/Workflow/Util.pm       | 15 ++++++++----
 .../Workflow/create_workflow_instance.pm      |  2 +-
 .../OpenXPKI/Server/Workflow/Persister/DBI.pm | 11 +++++----
 core/server/OpenXPKI/Workflow/Context.pm      |  7 +++---
 core/server/OpenXPKI/Workflow/Factory.pm      | 23 +++++++++++--------
 core/server/OpenXPKI/Workflow/Handler.pm      |  2 +-
 6 files changed, 35 insertions(+), 25 deletions(-)

diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/Util.pm b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/Util.pm
index 0d4ec9c348..c779475aef 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/Util.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/Util.pm
@@ -9,6 +9,7 @@ use Try::Tiny;
 use OpenXPKI::Server::Context qw( CTX );
 use OpenXPKI::Connector::WorkflowContext;
 use OpenXPKI::MooseParams;
+use OpenXPKI::Debug;
 
 =head2 validate_input_params
 
@@ -93,6 +94,7 @@ B<Positional parameters>
 =cut
 sub execute_activity {
     my ($self, $wf, $activity, $async, $wait) = @_;
+    ##! 2: 'execute activity ' . $activity
 
     # ASYNCHRONOUS - fork
     if ($async) {
@@ -130,6 +132,7 @@ B<Positional parameters>
 =cut
 sub _execute_activity_sync {
     my ($self, $workflow, $activity) = @_;
+    ##! 4: 'start'
 
     my $log = CTX('log')->workflow;
 
@@ -212,6 +215,7 @@ B<Positional parameters>
 =cut
 sub _execute_activity_async {
     my ($self, $workflow, $activity) = @_;
+    ##! 4: 'start'
 
     my $log = CTX('log')->workflow;
 
@@ -269,7 +273,7 @@ sub _execute_activity_async {
 # runs the given workflow activity on the Workflow engine
 sub _run_activity {
     my ($self, $wf, $ac) = @_;
-    ##! 8: 'execute activity ' . $ac
+    ##! 8: 'start'
 
     my $log = CTX('log')->workflow;
 
@@ -360,6 +364,7 @@ sub get_ui_info {
         attribute => { isa => 'Bool', optional => 1, default => 0 },
         activity  => { isa => 'Str',  optional => 1, },
     );
+    ##! 2: 'start'
 
     die "Please specify either 'id' or 'workflow'" unless ($args{id} or $args{workflow});
 
@@ -434,6 +439,7 @@ B<Positional parameters>:
 =cut
 sub get_ui_base_info {
     my ($self, $type) = @_;
+    ##! 2: 'start'
 
     # TODO we might use the OpenXPKI::Workflow::Config object for this
     # Note: Using create_workflow shreds a workflow id and creates an orphaned entry in the history table
@@ -479,6 +485,7 @@ sub get_ui_base_info {
 sub _get_config_details {
     my ($self, $factory, $type, $prefix, $state, $actions, $context) = @_;
     my $result = {};
+    ##! 4: 'start'
 
     # add activities (= actions)
     $result->{activity} = {};
@@ -551,8 +558,7 @@ B<Positional parameters>:
 =cut
 sub get_workflow_info {
     my ($self, $workflow) = @_;
-
-    ##! 1: "get_workflow_info"
+    ##! 2: 'start'
 
     ##! 64: Dumper $workflow
 
@@ -609,7 +615,7 @@ sub watch {
     my ($self, $workflow) = @_;
 
     my $timeout = time() + 15;
-    ##! 32:' Fork mode watch - timeout: '.$timeout
+    ##! 16: 'Fork mode watch - timeout: '.$timeout
 
     my $orig_state = {
         'state'       => $workflow->state,
@@ -647,6 +653,7 @@ sub watch {
 # Returns an instance of OpenXPKI::Server::Workflow
 sub fetch_workflow {
     my ($self, $type, $id) = @_;
+    ##! 2: 'start'
 
     my $factory = CTX('workflow_factory')->get_factory;
 
diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/create_workflow_instance.pm b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/create_workflow_instance.pm
index ba2bffafc2..b6651de682 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/create_workflow_instance.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/create_workflow_instance.pm
@@ -61,11 +61,11 @@ command "create_workflow_instance" => {
             message => "Could not start workflow (type might be unknown)",
             params => { type => $type }
         );
-
     $workflow->reload_observer;
 
     ## init creator
     my $id = $workflow->id;
+    ##! 2: "New workflow's ID: $id"
 
     Log::Log4perl::MDC->put('wfid',   $id);
     Log::Log4perl::MDC->put('wftype', $type);
diff --git a/core/server/OpenXPKI/Server/Workflow/Persister/DBI.pm b/core/server/OpenXPKI/Server/Workflow/Persister/DBI.pm
index 9a82df662e..a83890700a 100644
--- a/core/server/OpenXPKI/Server/Workflow/Persister/DBI.pm
+++ b/core/server/OpenXPKI/Server/Workflow/Persister/DBI.pm
@@ -57,10 +57,9 @@ sub update_workflow {
     my ($self, $workflow) = @_;
 
     my $id  = $workflow->id;
-    ##! 1: "Updating WF #$id"
+    ##! 1: "Saving WF #$id to DB"
     my $dbi = CTX('dbi');
 
-    ##! 1: "WF #$id: update_workflow"
     $self->__update_workflow($workflow);
 
     if ($workflow->persist_context) {
@@ -115,8 +114,8 @@ sub __update_workflow_context {
     my $params  = $context->param;
     my $dbi = CTX('dbi');
 
-    ##! 32: 'WF #$id: Context is ' . ref $context
-    ##! 128: 'WF #$id: Params from context: ' . Dumper $params
+    ##! 32: "WF #$id: Context is " . ref $context
+    ##! 128: "WF #$id: Params from context: " . Dumper $params
     my @updated = keys %{ $context->{_updated} };
 
     ##! 32: "WF #$id: Params with updates: " . join(":", @updated )
@@ -229,7 +228,7 @@ sub fetch_workflow {
     my $self = shift;
     my $id   = shift;
 
-    ##! 1: "fetch_workflow id: $id"
+    ##! 1: "id = $id"
 
     my $dbi = CTX("dbi");
 
@@ -402,6 +401,7 @@ sub fetch_history {
 }
 
 sub commit_transaction {
+    ##! 1: "COMMIT"
     CTX('log')->workflow->debug("Executing database COMMIT (requested by workflow engine)");
     CTX('dbi')->commit;
     CTX('dbi')->start_txn;
@@ -409,6 +409,7 @@ sub commit_transaction {
 }
 
 sub rollback_transaction {
+    ##! 1: "ROLLBACK"
     CTX('log')->workflow->debug("Executing database ROLLBACK (requested by workflow engine)");
     CTX('dbi')->rollback;
     CTX('dbi')->start_txn;
diff --git a/core/server/OpenXPKI/Workflow/Context.pm b/core/server/OpenXPKI/Workflow/Context.pm
index d88064f3c1..a9a3def233 100644
--- a/core/server/OpenXPKI/Workflow/Context.pm
+++ b/core/server/OpenXPKI/Workflow/Context.pm
@@ -27,20 +27,19 @@ sub reset_updated {
 }
 
 sub param {
-
     my $self = shift;
     my @arg = @_;
 
     my $name = shift @arg;
     if ( ref $name eq 'HASH' ) {
-        ##! 1: 'Mark updated from hash ' . join (",", keys %{$name})
+        ##! 16: 'Mark updated values from hash: ' . join (",", keys %{$name})
         map { $self->{_updated}->{$_} = 1; } keys %{$name};
 
     } elsif ( exists $arg[0] ) {
-        ##! 1: 'Mark updated from scalar ' . $name
+        ##! 16: 'Mark updated values from scalar: ' . $name
         $self->{_updated}->{$name} = 1;
     } else {
-        ##! 1: 'Call without value'
+        ##! 16: 'Call without value'
     }
 
     return $self->SUPER::param( @_ );
diff --git a/core/server/OpenXPKI/Workflow/Factory.pm b/core/server/OpenXPKI/Workflow/Factory.pm
index ea5d5a4dc1..2a3f6ddf7a 100644
--- a/core/server/OpenXPKI/Workflow/Factory.pm
+++ b/core/server/OpenXPKI/Workflow/Factory.pm
@@ -33,8 +33,8 @@ sub instance {
 }
 
 sub create_workflow{
-
     my ( $self, $wf_type, $context ) = @_;
+    ##! 1: 'start'
 
     $self->__authorize_workflow({
         ACTION => 'create',
@@ -50,8 +50,9 @@ sub create_workflow{
 
 sub fetch_workflow {
     my ( $self, $wf_type, $wf_id ) = @_;
+    ##! 1: 'start'
 
-
+    ##! 2: 'calling Workflow::Factory::fetch_workflow()'
     my $wf = $self->SUPER::fetch_workflow($wf_type, $wf_id, undef, 'OpenXPKI::Server::Workflow' )
         or OpenXPKI::Exception->throw(
             message => 'Requested workflow not found',
@@ -80,6 +81,8 @@ sub fetch_workflow {
 
 sub fetch_unfiltered_workflow {
     my ( $self, $wf_type, $wf_id ) = @_;
+    ##! 1: 'start'
+
     my $wf = $self->SUPER::fetch_workflow($wf_type, $wf_id, undef, 'OpenXPKI::Server::Workflow' )
         or OpenXPKI::Exception->throw(
             message => 'Requested workflow not found',
@@ -102,8 +105,8 @@ sub fetch_unfiltered_workflow {
 }
 
 sub list_workflow_titles {
-
     my $self = shift;
+    ##! 1: 'start'
 
     my $result = {};
     # Nothing initialised
@@ -128,10 +131,11 @@ be useful to merge this into a helper. Might be useful in the API.
 
 =cut
 sub get_action_info {
-
     my $self = shift;
     my $action_name = shift;
     my $wf_name = shift; # this can be replaced after creating a lookup map for prefix -> workflow
+    ##! 1: 'start'
+
     my $conn = CTX('config');
 
     # Check if it is a global or local action
@@ -171,10 +175,10 @@ sub get_action_info {
 }
 
 sub get_field_info {
-
     my $self = shift;
     my $field_name = shift;
     my $wf_name = shift;
+    ##! 1: 'start'
 
     my $conn = CTX('config');
 
@@ -218,9 +222,9 @@ access it granted).
 =cut
 
 sub authorize_workflow {
-
     my $self     = shift;
     my $arg_ref  = shift;
+    ##! 1: 'start'
 
     eval {
         $self->__authorize_workflow( $arg_ref );
@@ -234,9 +238,9 @@ sub authorize_workflow {
 
 
 sub __authorize_workflow {
-
     my $self     = shift;
     my $arg_ref  = shift;
+    ##! 1: 'start'
 
     my $conn = CTX('config');
 
@@ -350,9 +354,8 @@ authorize the current user.
 =cut
 
 sub check_acl {
-
-    my $self = shift;
-    my ($type, $wf_creator, $user, $role) = @_;
+    my ($self, $type, $wf_creator, $user, $role) = @_;
+    ##! 1: 'start'
 
     if (!$user) {
         $user = CTX('session')->data->user;
diff --git a/core/server/OpenXPKI/Workflow/Handler.pm b/core/server/OpenXPKI/Workflow/Handler.pm
index 847eaa8440..543ef344d0 100644
--- a/core/server/OpenXPKI/Workflow/Handler.pm
+++ b/core/server/OpenXPKI/Workflow/Handler.pm
@@ -57,6 +57,7 @@ OpenXPKI::Workflow.
 =cut
 sub get_workflow {
     my ($self, $args) = @_;
+    ##! 1: 'start'
 
     my $wf_id = $args->{ID};
 
@@ -137,7 +138,6 @@ Return a workflow factory using the versioned config.
 =cut
 sub get_factory {
     my ($self, $args) = @_;
-
     ##! 1: 'start'
     ##! 16: Dumper $args
 

From 6b368fb54ed8d031f5f1ed44d21920b1cfb05b0b Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Mon, 3 Sep 2018 22:32:10 +0200
Subject: [PATCH 18/22] Change an error message

---
 core/i18n/de_DE/openxpki.po                                   | 4 ----
 core/i18n/ru_RU/openxpki.po                                   | 4 ----
 core/server/OpenXPKI/Server/API/Workflow.pm                   | 2 +-
 .../Server/API2/Plugin/Workflow/get_workflow_type_for_id.pm   | 2 +-
 4 files changed, 2 insertions(+), 10 deletions(-)

diff --git a/core/i18n/de_DE/openxpki.po b/core/i18n/de_DE/openxpki.po
index 3e26017548..7d17110328 100644
--- a/core/i18n/de_DE/openxpki.po
+++ b/core/i18n/de_DE/openxpki.po
@@ -6466,10 +6466,6 @@ msgstr "Benutzername"
 #~ msgid "I18N_OPENXPKI_SERVER_API_WORKFLOW_GET_WORKFLOW_INFO_NO_WORKFLOW_GIVEN"
 #~ msgstr "Seriennummer des Workflowprozesses"
 
-#, fuzzy
-#~ msgid "I18N_OPENXPKI_SERVER_API_WORKFLOW_GET_WORKFLOW_TYPE_FOR_ID_NO_RESULT_FOR_ID"
-#~ msgstr "Seriennummer des Workflowprozesses"
-
 #, fuzzy
 #~ msgid "I18N_OPENXPKI_SERVER_API_WORKFLOW_MISSING_REQUIRED_FIELDS"
 #~ msgstr "Seriennummer des Workflowprozesses"
diff --git a/core/i18n/ru_RU/openxpki.po b/core/i18n/ru_RU/openxpki.po
index 76f54bf6b5..e70cc6328c 100644
--- a/core/i18n/ru_RU/openxpki.po
+++ b/core/i18n/ru_RU/openxpki.po
@@ -6494,10 +6494,6 @@ msgstr "Имя учетной записи"
 #~ msgid "I18N_OPENXPKI_SERVER_API_WORKFLOW_GET_WORKFLOW_INFO_NO_WORKFLOW_GIVEN"
 #~ msgstr "SPKAC-строка пуста."
 
-#, fuzzy
-#~ msgid "I18N_OPENXPKI_SERVER_API_WORKFLOW_GET_WORKFLOW_TYPE_FOR_ID_NO_RESULT_FOR_ID"
-#~ msgstr "SPKAC-строка пуста."
-
 #~ msgid "I18N_OPENXPKI_SERVER_API_WORKFLOW_MISSING_REQUIRED_FIELDS"
 #~ msgstr ""
 #~ "Для выполнения следющего действия технологическому процессу необходимы "
diff --git a/core/server/OpenXPKI/Server/API/Workflow.pm b/core/server/OpenXPKI/Server/API/Workflow.pm
index fe52266176..26beff4fd8 100644
--- a/core/server/OpenXPKI/Server/API/Workflow.pm
+++ b/core/server/OpenXPKI/Server/API/Workflow.pm
@@ -60,7 +60,7 @@ sub get_workflow_type_for_id {
         where => { workflow_id => $id },
     )
     or OpenXPKI::Exception->throw(
-        message => 'I18N_OPENXPKI_SERVER_API_WORKFLOW_GET_WORKFLOW_TYPE_FOR_ID_NO_RESULT_FOR_ID',
+        message => 'No workflow found with the given ID',
         params  => { ID => $id },
     );
     my $type = $db_result->{workflow_type};
diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/get_workflow_type_for_id.pm b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/get_workflow_type_for_id.pm
index 7041606206..85c08d2a5a 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/get_workflow_type_for_id.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/get_workflow_type_for_id.pm
@@ -40,7 +40,7 @@ command "get_workflow_type_for_id" => {
         where => { workflow_id => $id },
     )
     or OpenXPKI::Exception->throw(
-        message => 'I18N_OPENXPKI_SERVER_API_WORKFLOW_GET_WORKFLOW_TYPE_FOR_ID_NO_RESULT_FOR_ID',
+        message => 'No workflow found with the given ID',
         params  => { ID => $id },
     );
 

From d79a3747f1ea11062a7d4642dae1d78334fd9192 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Tue, 4 Sep 2018 00:03:48 +0200
Subject: [PATCH 19/22] Handle wf crashes in first action, save wf. in INITIAL
 state. Fixes #473

---
 .../Workflow/create_workflow_instance.pm      |  65 +++++-----
 core/server/OpenXPKI/Server/Workflow.pm       |  12 --
 qatest/backend/api2/42_workflow_resume.t      | 122 ++++++++++++++----
 3 files changed, 130 insertions(+), 69 deletions(-)

diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/create_workflow_instance.pm b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/create_workflow_instance.pm
index b6651de682..c04a44d67e 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/create_workflow_instance.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/create_workflow_instance.pm
@@ -6,6 +6,11 @@ use OpenXPKI::Server::API2::EasyPlugin;
 OpenXPKI::Server::API2::Plugin::Workflow::create_workflow_instance
 
 =cut
+# Core modules
+use Scalar::Util 'blessed';
+
+# CPAN modules
+use Try::Tiny;
 
 # Project modules
 use OpenXPKI::Server::Context qw( CTX );
@@ -94,49 +99,47 @@ command "create_workflow_instance" => {
             params => { type => $type }
         );
     }
-    my $initial_action = shift @actions;
 
-    ##! 8: "initial action: " . $initial_action
+    my $updated_workflow = $workflow;
 
-    # check the input params
-    my $wf_params = $util->validate_input_params($workflow, $initial_action, $params->params);
-    ##! 16: ' initial params ' . Dumper  $wf_params
+    # executing INITAL action: might throw exceptions which are usually caught,
+    # handled and rethrown deeper down the hierarchy
+    try {
+        my $initial_action = shift @actions;
 
-    $context->param($wf_params) if $wf_params;
+        ##! 8: "initial action: " . $initial_action
 
-    ##! 64: Dumper $workflow
+        # check the input params
+        my $wf_params = $util->validate_input_params($workflow, $initial_action, $params->params);
+        ##! 16: ' initial params ' . Dumper  $wf_params
 
-    $util->execute_activity($workflow, $initial_action);
+        $context->param($wf_params) if $wf_params;
 
-    # FIXME - ported from old factory but I do not understand if this ever can happen..
-    # From theory, the workflow should throw an exception if the action can not be handled
-    # Workflow is still in initial state - so something went wrong.
-    if ($workflow->state eq 'INITIAL') {
-        OpenXPKI::Exception->throw (
-            message => "Failed to create workflow instance!",
-            log =>  {
-                priority => 'error',
-                facility => 'workflow'
-            }
-        );
-    }
+        ##! 64: Dumper $workflow
 
-    # check back for the creator in the context and copy it to the attribute table
-    # doh - somebody deleted the creator from the context
-    $context->param('creator' => $creator) unless $context->param('creator');
-    $workflow->attrib({ creator => $context->param('creator') });
+        # $updated_workflow is the same as $workflow as long as we do not execute
+        # the first workflow step asynchronously: execute_activity(..., async => 1, wait => 1)
+        $updated_workflow = $util->execute_activity($workflow, $initial_action);
 
-    # TODO - we need to persist the workflow here again!
+        # check back for the creator in the context and copy it to the attribute table
+        # doh - somebody deleted the creator from the context
+        $context->param('creator' => $creator) unless $context->param('creator');
+        $workflow->attrib({ creator => $context->param('creator') });
+    }
+    catch {
+        # Safety net: bubble up unknown exceptions.
+        # We assume that all OpenXPKI::Exception that may occur have already
+        # been handled properly further down the execution chain
+        die $_ unless blessed $_ && $_->isa('OpenXPKI::Exception');
+    };
 
     Log::Log4perl::MDC->put('wfid',   undef);
     Log::Log4perl::MDC->put('wftype', undef);
 
-    if ($params->ui_info) {
-        return $util->get_ui_info(workflow => $workflow);
-    }
-    else {
-        return $util->get_workflow_info($workflow);
-    }
+    return ($params->ui_info
+        ? $util->get_ui_info(workflow => $updated_workflow)
+        : $util->get_workflow_info($updated_workflow)
+    );
 };
 
 __PACKAGE__->meta->make_immutable;
diff --git a/core/server/OpenXPKI/Server/Workflow.pm b/core/server/OpenXPKI/Server/Workflow.pm
index 92055a64fc..a54ec22d16 100644
--- a/core/server/OpenXPKI/Server/Workflow.pm
+++ b/core/server/OpenXPKI/Server/Workflow.pm
@@ -712,18 +712,6 @@ sub _save {
     my $self = shift;
     ##! 16: 'save workflow!'
 
-    # do not save if we are in the startup phase of a workflow
-    # Some niffy tasks create broken workflows for validating
-    # parameters and we will get tons of init/exception entries
-    my $proc_state = $self->proc_state;
-
-    if ($self->state() eq 'INITIAL' &&
-        ($proc_state eq 'init' || $proc_state eq 'running' || $proc_state eq 'exception' )) {
-        CTX('log')->workflow()->debug("Workflow save requested during startup - wont save! ($proc_state)");
-        ##! 16: sprintf 'dont save as we are in startup phase (proc state %s) !', $proc_state ;
-        return;
-    }
-
     $self->_factory()->save_workflow($self);
 
     # If using a DBI persister with no autocommit, commit here.
diff --git a/qatest/backend/api2/42_workflow_resume.t b/qatest/backend/api2/42_workflow_resume.t
index ec627ad7c9..4fa84b4c61 100644
--- a/qatest/backend/api2/42_workflow_resume.t
+++ b/qatest/backend/api2/42_workflow_resume.t
@@ -8,22 +8,24 @@ use FindBin qw( $Bin );
 
 # CPAN modules
 use Test::More;
+use Test::Exception;
 use Data::UUID;
 
 # Project modules
 use lib $Bin, "$Bin/../../lib", "$Bin/../../../core/server/t/lib";
+#use OpenXPKI::Debug; BEGIN { $OpenXPKI::Debug::LEVEL{'OpenXPKI::Server.*'} = 4; $OpenXPKI::Debug::LEVEL{'.*Workflow.*'} = 8 }
 use OpenXPKI::Test;
 
-plan tests => 3;
+plan tests => 2;
 
 #
 # Setup test context
 #
-my $workflow_def = {
+my $workflow_def1 = {
     'head' => {
-        'label' => 'wf_that_explodes',
+        'label' => 'wf_that_explodes1',
         'persister' => 'OpenXPKI',
-        'prefix' => 'wfthatexplodes',
+        'prefix' => 'wfthatexplodes1',
     },
     'state' => {
         'INITIAL' => {
@@ -36,10 +38,6 @@ my $workflow_def = {
             'label' => 'Done',
             'description' => 'We are finished',
         },
-        'FAILURE' => {
-            'label' => 'Workflow has failed',
-            'description' => 'We are sorry',
-        },
     },
     'action' => {
         'noop' => {
@@ -54,12 +52,38 @@ my $workflow_def = {
     },
 };
 
+my $workflow_def2 = {
+    'head' => {
+        'label' => 'wf_that_explodes2',
+        'persister' => 'OpenXPKI',
+        'prefix' => 'wfthatexplodes2',
+    },
+    'state' => {
+        'INITIAL' => {
+            'action' => [ 'boom > SUCCESS' ],
+        },
+        'SUCCESS' => {
+            'label' => 'Done',
+            'description' => 'We are finished',
+        },
+    },
+    'action' => {
+        'boom' => {
+            'class' => 'TestWorkflowActivityWithException',
+        },
+    },
+    'acl' => {
+        'User' => { creator => 'any', techlog => 1, history => 1 },
+    },
+};
+
 my $uuid = Data::UUID->new->create_str; # so we don't see workflows from previous test runs
 
 my $oxitest = OpenXPKI::Test->new(
     with => [ qw( TestRealms Workflows ) ],
     add_config => {
-        "realm.alpha.workflow.def.wf_that_explodes" => $workflow_def,
+        "realm.alpha.workflow.def.wf_that_explodes1_$uuid" => $workflow_def1,
+        "realm.alpha.workflow.def.wf_that_explodes2_$uuid" => $workflow_def2,
     },
     #log_level => "debug",
 );
@@ -75,27 +99,73 @@ CTX('session')->data->user('wilhelm');
 package TestWorkflowResume;
 package main;
 
-$TestWorkflowResume::trigger_exception = 1; # this will be used in TestWorkflowActivityWithException to trigger the exception
-my $wf = $oxitest->create_workflow("wf_that_explodes");
-
-my $result = $oxitest->api2_command("execute_workflow_activity" => {
-    id => $wf->id,
-    activity => "wfthatexplodes_throw_exception",
-    async => 1,
-    wait => 1,
-});
-
-is $result->{workflow}->{proc_state}, "exception", "workflow is in EXCEPTION state";
-
-$TestWorkflowResume::trigger_exception = 0; # this will be used in TestWorkflowActivityWithException to trigger the exception
-my $info = $oxitest->api2_command("resume_workflow" => { id => $wf->id, async => 1, wait => 1 });
+#
+# Test A: crash on some action
+#
+subtest "workflow crashing on some action" => sub {
+    plan tests => 6;
+
+    $TestWorkflowResume::trigger_exception = 1; # this will be used in TestWorkflowActivityWithException to trigger the exception
+    my $wf;
+    lives_ok {
+        $wf = $oxitest->create_workflow("wf_that_explodes1_$uuid");
+    } "workflow is created";
+
+    my $result;
+    lives_ok {
+        $result = $oxitest->api2_command("execute_workflow_activity" => {
+            id => $wf->id,
+            activity => "wfthatexplodes1_throw_exception",
+            # async and wait prevent the API call from throwing an exception
+            async => 1,
+            wait => 1,
+        });
+    } "workflow activity is executed (and crashes in the background)";
+
+    is $result->{workflow}->{proc_state}, "exception", "workflow is in EXCEPTION state";
+
+    $TestWorkflowResume::trigger_exception = 0; # this will be used in TestWorkflowActivityWithException to trigger the exception
+    my $info;
+    lives_ok {
+        $info = $oxitest->api2_command("resume_workflow" => { id => $wf->id, async => 1, wait => 1 });
+    } "resume workflow";
+
+    is $info->{workflow}->{proc_state}, "finished", "workflow is finished";
+    is $info->{workflow}->{state}, "SUCCESS", "workflow is in state SUCCESS";
+};
 
-is $info->{workflow}->{proc_state}, "finished", "workflow is finished";
-is $info->{workflow}->{state}, "SUCCESS", "workflow is in state SUCCESS";
+#
+# Test B: crash on INITIAL action
+#
+subtest "workflow crashing on INITIAL action" => sub {
+    plan tests => 5;
+
+    $TestWorkflowResume::trigger_exception = 1; # this will be used in TestWorkflowActivityWithException to trigger the exception
+
+    my $wf;
+    lives_and {
+        $wf = $oxitest->create_workflow("wf_that_explodes2_$uuid");
+        like $wf->id, qr/^\d+$/;
+    } "create_workflow() returns after crash in INITIAL action";
+
+    lives_and {
+        my $info = $oxitest->api2_command("get_workflow_info" => { id => $wf->id });
+        is $info->{workflow}->{proc_state}, "exception", "workflow is in EXCEPTION state";
+    } "workflow was persisted";
+
+    $TestWorkflowResume::trigger_exception = 0; # this will be used in TestWorkflowActivityWithException to trigger the exception
+    my $info;
+    lives_ok {
+        $info = $oxitest->api2_command("resume_workflow" => { id => $wf->id, async => 1, wait => 1 });
+    } "resume workflow";
+
+    is $info->{workflow}->{proc_state}, "finished", "workflow is finished";
+    is $info->{workflow}->{state}, "SUCCESS", "workflow is in state SUCCESS";
+};
 
 # delete test workflows
 $oxitest->dbi->start_txn;
-$oxitest->dbi->delete(from => 'workflow', where => { workflow_type => "wf_that_explodes" } );
+$oxitest->dbi->delete(from => 'workflow', where => { workflow_type => [ -like => "%$uuid" ] } );
 $oxitest->dbi->commit;
 
 1;

From 15b3919f0c8d25dd3ee0c46c0f1c866093019636 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Tue, 4 Sep 2018 00:09:47 +0200
Subject: [PATCH 20/22] Prevent unneccessary DB lookup

---
 .../Server/API2/Plugin/Workflow/execute_workflow_activity.pm    | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/execute_workflow_activity.pm b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/execute_workflow_activity.pm
index a2b4aaa903..e06681d619 100644
--- a/core/server/OpenXPKI/Server/API2/Plugin/Workflow/execute_workflow_activity.pm
+++ b/core/server/OpenXPKI/Server/API2/Plugin/Workflow/execute_workflow_activity.pm
@@ -116,7 +116,7 @@ command "execute_workflow_activity" => {
     my $updated_workflow = $util->execute_activity($workflow, $wf_activity, $params->async, $params->wait);
 
     return ($params->ui_info
-        ? $util->get_ui_info(id => $wf_id)
+        ? $util->get_ui_info(workflow => $updated_workflow)
         : $util->get_workflow_info($updated_workflow)
     );
 };

From 1b60b1a7a8793f0206fe5492d896e3c6113caa0c Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Tue, 4 Sep 2018 00:34:25 +0200
Subject: [PATCH 21/22] Add test for API command 'private_key_exists_for_cert'

---
 qatest/backend/nice/10_nice_signing_request.t | 7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

diff --git a/qatest/backend/nice/10_nice_signing_request.t b/qatest/backend/nice/10_nice_signing_request.t
index 8947813f1b..79b5ce8f31 100644
--- a/qatest/backend/nice/10_nice_signing_request.t
+++ b/qatest/backend/nice/10_nice_signing_request.t
@@ -17,7 +17,7 @@ use lib $Bin, "$Bin/../../lib", "$Bin/../../../core/server/t/lib";
 use OpenXPKI::Test;
 
 
-plan tests => 30;
+plan tests => 31;
 
 
 #
@@ -153,6 +153,11 @@ lives_and {
     isnt $privkey, "";
 } "Fetch PKCS12";
 
+lives_and {
+    my $exists = $oxitest->api2_command('private_key_exists_for_cert' => { identifier => $cert_id } );
+    is $exists, 1;
+} "confirm that private key exists";
+
 my ($tmp, $tmp_name) = tempfile(UNLINK => 1);
 print $tmp $privkey;
 close $tmp;

From df0b26adb355e5398f4eb779e17621eb00819483 Mon Sep 17 00:00:00 2001
From: Jens Berthold <jens@jebecs.de>
Date: Tue, 4 Sep 2018 00:37:30 +0200
Subject: [PATCH 22/22] Modify test to use new API2

---
 qatest/backend/nice/10_nice_signing_request.t | 26 +++++++++----------
 1 file changed, 13 insertions(+), 13 deletions(-)

diff --git a/qatest/backend/nice/10_nice_signing_request.t b/qatest/backend/nice/10_nice_signing_request.t
index 79b5ce8f31..ac302ecb44 100644
--- a/qatest/backend/nice/10_nice_signing_request.t
+++ b/qatest/backend/nice/10_nice_signing_request.t
@@ -91,8 +91,8 @@ $wf->state_is('SUBJECT_COMPLETE');
 
 # Nicetest FQDNs should not validate so we need a policy expcetion request
 # (on rare cases the responsible router might return a valid address, so we check)
-my $result = $oxitest->api_command('get_workflow_info' => { ID => $wf->id });
-my $actions = $result->{STATE}->{option};
+my $result = $oxitest->api2_command('get_workflow_info' => { id => $wf->id });
+my $actions = $result->{state}->{option};
 my $intermediate_state;
 if (grep { /^csr_enter_policy_violation_comment$/ } @$actions) {
     note "Test FQDNs do not resolve - handling policy violation";
@@ -128,8 +128,8 @@ $wf->execute('csr_approve_csr');
 
 $wf->state_is('SUCCESS');
 
-my $info = $oxitest->api_command('get_workflow_info' => { ID => $wf->id } );
-like $info->{WORKFLOW}->{CONTEXT}->{cert_subject}, "/^CN=$subject:8080,.*/", 'correct certificate subject';
+my $info = $oxitest->api2_command('get_workflow_info' => { id => $wf->id } );
+like $info->{workflow}->{context}->{cert_subject}, "/^CN=$subject:8080,.*/", 'correct certificate subject';
 
 
 # set current user to: normal user
@@ -139,8 +139,8 @@ $oxitest->set_user('ca-one' => 'user');
 #
 # Fetch certificate via API
 #
-$info = $oxitest->api_command('get_workflow_info' => { ID => $wf->id } );
-my $cert_id = $info->{WORKFLOW}->{CONTEXT}->{cert_identifier};
+$info = $oxitest->api2_command('get_workflow_info' => { id => $wf->id } );
+my $cert_id = $info->{workflow}->{context}->{cert_identifier};
 note "Test certificate ID: $cert_id";
 
 #
@@ -148,10 +148,10 @@ note "Test certificate ID: $cert_id";
 #
 my $privkey;
 lives_and {
-    my $result = $oxitest->api_command('get_private_key_for_cert' => { IDENTIFIER => $cert_id, FORMAT => 'PKCS12', 'PASSWORD' => 'm4#bDf7m3abd' } );
-    $privkey = $result->{PRIVATE_KEY};
+    my $result = $oxitest->api2_command('get_private_key_for_cert' => { identifier => $cert_id, format => 'PKCS12', 'password' => 'm4#bDf7m3abd' } );
+    $privkey = $result;
     isnt $privkey, "";
-} "Fetch PKCS12";
+} "Fetch PKCS12 private key";
 
 lives_and {
     my $exists = $oxitest->api2_command('private_key_exists_for_cert' => { identifier => $cert_id } );
@@ -172,7 +172,7 @@ like `openssl pkcs12 -in $tmp_name -nokeys -noout -passin pass:'m4#bDf7m3abd' 2>
 # cert profile
 #
 lives_and {
-    my $result = $oxitest->api_command('get_profile_for_cert' => { IDENTIFIER => $cert_id });
+    my $result = $oxitest->api2_command('get_profile_for_cert' => { identifier => $cert_id });
     is $result, "I18N_OPENXPKI_PROFILE_TLS_SERVER";
 } "query certificate profile";
 
@@ -180,7 +180,7 @@ lives_and {
 # cert actions
 #
 lives_and {
-    my $result = $oxitest->api_command('get_cert_actions' => { IDENTIFIER => $cert_id, ROLE => "User" });
+    my $result = $oxitest->api2_command('get_cert_actions' => { identifier => $cert_id, role => "User" });
     cmp_deeply $result, superhashof({
         # actions are defined in config/openxpki/config.d/realm/ca-one/uicontrol/_default.yaml,
         # they must exist and "User" must be defined in their "acl" section as creator
@@ -203,9 +203,9 @@ lives_and {
 # the workflow automatically sets this to the workflow creator, which in our
 # case is "user" (see session user in OpenXPKI::Test::QA::Role::WorkflowCreateCert->create_cert)
 lives_and {
-    is $oxitest->api_command('is_certificate_owner' => { IDENTIFIER => $cert_id, USER => $user }), 1;
+    is $oxitest->api2_command('is_certificate_owner' => { identifier => $cert_id, user => $user }), 1;
 } "confirm correct certificate owner";
 
 lives_and {
-    isnt $oxitest->api_command('is_certificate_owner' => { IDENTIFIER => $cert_id, USER => 'nerd' }), 1;
+    isnt $oxitest->api2_command('is_certificate_owner' => { identifier => $cert_id, user => 'nerd' }), 1;
 } "negate wrong certificate owner";