Merge branch 'issue-2155' into calamares

src/libcalamares/utils/CommandList.cpp

@@ -16,6 +16,7 @@
 #include "compat/Variant.h"
 #include "locale/Global.h"
 #include "utils/Logger.h"
+#include "utils/Runner.h"
 #include "utils/StringExpander.h"
 #include "utils/System.h"
 #include "utils/Variant.h"
@@ -140,6 +141,11 @@ CommandLine::CommandLine( const QVariantMap& m )
         m_command = command;
         m_timeout = timeout >= 0 ? std::chrono::seconds( timeout ) : CommandLine::TimeoutNotSet();
         m_environment = Calamares::getStringList( m, "environment" );
+
+        if ( m.contains( "verbose" ) )
+        {
+            m_verbose = Calamares::getBool( m, "verbose", false );
+        }
     }
     else
     {
@@ -159,7 +165,12 @@ CommandLine::expand( KMacroExpanderBase& expander ) const
     QStringList e = m_environment;
     std::for_each( e.begin(), e.end(), [ &expander ]( QString& s ) { expander.expandMacrosShellQuote( s ); } );
 
-    return { c, m_environment, m_timeout };
+    CommandLine l { c, m_environment, m_timeout };
+    if ( m_verbose.has_value() )
+    {
+        l.updateVerbose( m_verbose.value() );
+    }
+    return l;
 }
 
 Calamares::CommandLine
@@ -252,7 +263,16 @@ CommandList::run()
         shell_cmd << ( environmentSetting + processed_cmd );
 
         std::chrono::seconds timeout = i->timeout() >= std::chrono::seconds::zero() ? i->timeout() : m_timeout;
-        ProcessResult r = System::runCommand( location, shell_cmd, QString(), QString(), timeout );
+
+        Calamares::Utils::Runner runner( shell_cmd );
+        runner.setLocation( location ).setTimeout( timeout ).setWorkingDirectory( QString() );
+        if ( i->isVerbose() )
+        {
+            runner.enableOutputProcessing();
+            QObject::connect(
+                &runner, &Calamares::Utils::Runner::output, []( QString output ) { cDebug() << output; } );
+        }
+        ProcessResult r = runner.run();
 
         if ( r.getExitCode() != 0 )
         {
@@ -289,4 +309,10 @@ CommandList::expand() const
     return expand( expander );
 }
 
+void
+CommandList::updateVerbose( bool verbose )
+{
+    std::for_each( begin(), end(), [ verbose ]( CommandLine& command ) { command.updateVerbose( verbose ); } );
+}
+
 }  // namespace Calamares

src/libcalamares/utils/CommandList.h

@@ -18,6 +18,7 @@
 #include <QVariant>
 
 #include <chrono>
+#include <optional>
 #include <utility>
 
 class KMacroExpanderBase;
@@ -63,6 +64,7 @@ public:
     QString command() const { return m_command; }
     [[nodiscard]] QStringList environment() const { return m_environment; }
     std::chrono::seconds timeout() const { return m_timeout; }
+    bool isVerbose() const { return m_verbose.value_or( false ); }
 
     bool isValid() const { return !m_command.isEmpty(); }
 
@@ -81,10 +83,20 @@ public:
      */
     DLLEXPORT CommandLine expand() const;
 
+    /** @brief If nothing has set verbosity yet, update to @p verbose */
+    void updateVerbose( bool verbose )
+    {
+        if ( !m_verbose.has_value() )
+        {
+            m_verbose = verbose;
+        }
+    }
+
 private:
     QString m_command;
     QStringList m_environment;
     std::chrono::seconds m_timeout = TimeoutNotSet();
+    std::optional< bool > m_verbose;
 };
 
 /** @brief Abbreviation, used internally. */
@@ -103,6 +115,11 @@ class DLLEXPORT CommandList : protected CommandList_t
 public:
     /** @brief empty command-list with timeout to apply to entries. */
     CommandList( bool doChroot = true, std::chrono::seconds timeout = std::chrono::seconds( 10 ) );
+    /** @brief command-list constructed from script-entries in @p v
+     *
+     * The global settings @p doChroot and @p timeout can be overridden by
+     * the individual script-entries.
+     */
     CommandList( const QVariant& v, bool doChroot = true, std::chrono::seconds timeout = std::chrono::seconds( 10 ) );
     CommandList( int ) = delete;
     CommandList( const QVariant&, int ) = delete;
@@ -126,14 +143,17 @@ public:
      * Each command-line in the list is expanded with the given @p expander.
      * @see CommandLine::expand() for details.
      */
-    CommandList expand( KMacroExpanderBase& expander ) const;
+    DLLEXPORT CommandList expand( KMacroExpanderBase& expander ) const;
 
     /** @brief As above, with a default macro-expander.
      *
      * Each command-line in the list is expanded with that default macro-expander.
      * @see CommandLine::expand() for details.
      */
-    CommandList expand() const;
+    DLLEXPORT CommandList expand() const;
+
+    /** @brief Applies default-value @p verbose to each entry without an explicit setting. */
+    DLLEXPORT void updateVerbose( bool verbose );
 
 private:
     bool m_doChroot;

src/libcalamares/utils/Runner.cpp

@@ -189,8 +189,9 @@ Calamares::Utils::Runner::run()
                                        ? ( static_cast< int >( std::chrono::milliseconds( m_timeout ).count() ) )
                                        : -1 ) )
     {
-        cWarning() << "Process" << m_command.first() << "timed out after" << m_timeout.count() << "ms. Output so far:\n"
-                   << Logger::NoQuote << process.readAllStandardOutput();
+        cWarning() << "Process" << m_command.first() << "timed out after" << m_timeout.count() << "ms."
+                   << Logger::NoQuote << "Output so far:\n"
+                   << process.readAllStandardOutput();
         return ProcessResult::Code::TimedOut;
     }
 
@@ -216,7 +217,7 @@ Calamares::Utils::Runner::run()
 
     if ( process.exitStatus() == QProcess::CrashExit )
     {
-        cWarning() << "Process" << m_command.first() << "crashed. Output so far:\n" << Logger::NoQuote << output;
+        cWarning() << "Process" << m_command.first() << "crashed." << Logger::NoQuote << "Output so far:\n" << output;
         return ProcessResult::Code::Crashed;
     }
 
@@ -226,7 +227,7 @@ Calamares::Utils::Runner::run()
     {
         if ( showDebug && !output.isEmpty() )
         {
-            cDebug() << Logger::SubEntry << "Finished. Exit code:" << r << "output:\n" << Logger::NoQuote << output;
+            cDebug() << Logger::SubEntry << "Finished. Exit code:" << r << Logger::NoQuote << "output:\n" << output;
         }
     }
     else  // if ( r != 0 )
@@ -234,8 +235,8 @@ Calamares::Utils::Runner::run()
         if ( !output.isEmpty() )
         {
             cDebug() << Logger::SubEntry << "Target cmd:" << Logger::RedactedCommand( m_command ) << "Exit code:" << r
-                     << "output:\n"
-                     << Logger::NoQuote << output;
+                     << Logger::NoQuote << "output:\n"
+                     << output;
         }
         else
         {

src/libcalamares/utils/Tests.cpp

@@ -31,6 +31,8 @@
 
 #include <QtTest/QtTest>
 
+#include <utility>
+
 #include <fcntl.h>
 #include <sys/stat.h>
 #include <unistd.h>
@@ -56,6 +58,8 @@ private Q_SLOTS:
     void testCommandConstructors();
     void testCommandConstructorsYAML();
     void testCommandRunning();
+    void testCommandTimeout();
+    void testCommandVerbose();
 
     /** @section Test that all the UMask objects work correctly. */
     void testUmask();
@@ -454,6 +458,89 @@ LibCalamaresTests::testCommandRunning()
     tempRoot.setAutoRemove( true );
 }
 
+void
+LibCalamaresTests::testCommandTimeout()
+{
+
+    QTemporaryDir tempRoot( QDir::tempPath() + QStringLiteral( "/test-job-XXXXXX" ) );
+    tempRoot.setAutoRemove( false );
+
+    const QString testExecutable = tempRoot.filePath( "example.sh" );
+
+    cDebug() << "Creating example executable" << testExecutable;
+
+    {
+        QFile f( testExecutable );
+        QVERIFY( f.open( QIODevice::WriteOnly ) );
+        f.write( "#! /bin/sh\necho early\nsleep 3\necho late" );
+        f.close();
+        Calamares::Permissions::apply( testExecutable, 0755 );
+    }
+
+    {
+        Calamares::CommandList l( false );  // no chroot
+        Calamares::CommandLine c( testExecutable, {}, std::chrono::seconds( 2 ) );
+        l.push_back( c );
+
+        const auto r = l.run();
+        QVERIFY( !bool( r ) );  // Because it times out after 2 seconds
+        // The **command** timed out, but the job result is a generic "error"
+        // QCOMPARE( r.errorCode(), static_cast<std::underlying_type_t<Calamares::ProcessResult::Code>>(Calamares::ProcessResult::Code::TimedOut));
+        QCOMPARE( r.errorCode(), -1 );
+    }
+}
+
+void
+LibCalamaresTests::testCommandVerbose()
+{
+    Logger::setupLogLevel( Logger::LOGDEBUG );
+
+    QTemporaryDir tempRoot( QDir::tempPath() + QStringLiteral( "/test-job-XXXXXX" ) );
+    tempRoot.setAutoRemove( false );
+
+    const QString testExecutable = tempRoot.filePath( "example.sh" );
+
+    cDebug() << "Creating example executable" << testExecutable;
+    {
+        QFile f( testExecutable );
+        QVERIFY( f.open( QIODevice::WriteOnly ) );
+        f.write( "#! /bin/sh\necho one\necho two\necho error 1>&2\nsleep 1; echo three\n" );
+        f.close();
+        Calamares::Permissions::apply( testExecutable, 0755 );
+    }
+
+    // Note that, because of the blocking way run() works,
+    // in this single-threaded test with no event loop,
+    // there's nothing for the verbose version to connect
+    // to for sending output.
+
+    cDebug() << "Running command non-verbose";
+    {
+        Calamares::CommandList l( false );  // no chroot
+        Calamares::CommandLine c( testExecutable, {}, std::chrono::seconds( 2 ) );
+        c.updateVerbose( false );
+        QVERIFY( !c.isVerbose() );
+
+        l.push_back( c );
+
+        const auto r = l.run();
+        QVERIFY( bool( r ) );
+    }
+
+    cDebug() << "Running command verbosely";
+    {
+        Calamares::CommandList l( false );  // no chroot
+        Calamares::CommandLine c( testExecutable, {}, std::chrono::seconds( 2 ) );
+        c.updateVerbose( true );
+        QVERIFY( c.isVerbose() );
+
+        l.push_back( c );
+
+        const auto r = l.run();
+        QVERIFY( bool( r ) );
+    }
+}
+
 void
 LibCalamaresTests::testUmask()
 {

src/modules/shellprocess/ShellProcessJob.cpp

@@ -60,6 +60,7 @@ ShellProcessJob::setConfigurationMap( const QVariantMap& configurationMap )
     {
         timeout = 30;
     }
+    bool verbose = Calamares::getBool( configurationMap, "verbose", false );
 
     if ( configurationMap.contains( "script" ) )
     {
@@ -69,6 +70,7 @@ ShellProcessJob::setConfigurationMap( const QVariantMap& configurationMap )
         {
             cDebug() << "ShellProcessJob: \"script\" contains no commands for" << moduleInstanceKey();
         }
+        m_commands->updateVerbose( verbose );
     }
     else
     {

src/modules/shellprocess/shellprocess.conf

@@ -84,8 +84,20 @@
 ---
 # Set to true to run in host, rather than target system
 dontChroot: false
-# Tune this for the commands you're actually running
-# timeout: 10
+
+# Tune this for the commands you're actually running, or
+# use the list-of-items form of commands to tune the timeout
+# for each command individually.
+timeout: 10
+
+# This will copy the output from the command into the Calamares
+# log file. No processing is done beyond log-each-line-separately,
+# so this can introduce weirdness in the log if the script
+# outputs e.g. escape codes.
+#
+# The default is `false`. This can also be set for each
+# command individually.
+verbose: false
 
 # Script may be a single string (because false returns an error exit
 # code, this will trigger a failure in the installation):
@@ -109,6 +121,8 @@ script:
     - "/usr/bin/true"
     - command: "/usr/local/bin/slowloris"
       timeout: 3600
+    - command: "echo -e '\e[33;2mred\e[33;0m'"
+      verbose: true
 
 # You can change the description of the job (as it is displayed in the
 # progress bar during installation) by defining an *i18n* key, which

src/modules/shellprocess/shellprocess.schema.yaml

@@ -19,7 +19,10 @@ definitions:
       timeout:
         type: number
         description: the (optional) timeout for this specific command (differently
-          from the global setting)
+          from the global setting).
+      verbose:
+        type: boolean
+        description: when true, log output from the command to the Calamares log.
     required:
     - command
 type: object
@@ -34,6 +37,9 @@ properties:
     type: number
     description: The (global) timeout for the command list in seconds. If unset, defaults
       to 30 seconds.
+  verbose:
+    type: boolean
+    description: when true, log output from the command to the Calamares log.
   script:
     anyOf:
     - $ref: '#definitions/command'
@@ -55,3 +61,5 @@ properties:
         type: string
     required:
     - name
+required:
+  - script