Merge pull request #1270 from mattias-symphony/SDA-3370

SDA-3370 Changing the flow to handle reboot of service during installation
This commit is contained in:
mattias-symphony 2021-10-12 14:26:39 +02:00 committed by GitHub
commit a89310c58e
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
4 changed files with 205 additions and 47 deletions

View File

@ -1,6 +1,8 @@
#define _CRT_SECURE_NO_WARNINGS
#define _CRT_NONSTDC_NO_WARNINGS
//#define LOG_TO_CONSOLE_FOR_DEBUGGING
#include <windows.h>
#include <aclapi.h>
#pragma comment(lib, "advapi32.lib")
@ -89,7 +91,11 @@ void log_init( char const* filename ) {
InitializeCriticalSection( &g_log.mutex );
if( filename ) {
g_log.file = fopen( filename, "w" );
#ifndef LOG_TO_CONSOLE_FOR_DEBUGGING
g_log.file = fopen( filename, "w" );
#else
g_log.file = stdout;
#endif
time_t rawtime = time( NULL );
struct tm* ptm = gmtime( &rawtime );
@ -100,7 +106,7 @@ void log_init( char const* filename ) {
}
int main( int argc, char** argv ) {
int main( int argc, char* argv[] ) {
// Find argument ending with .log, if any
char const* log_filename = NULL;
for( int i = 0; i < argc; ++i ) {
@ -110,6 +116,10 @@ int main( int argc, char** argv ) {
break;
}
}
if( !log_filename ) {
return EXIT_FAILURE;
}
// Initialize logging
log_init( log_filename );
@ -132,13 +142,14 @@ int main( int argc, char** argv ) {
LOG_INFO( "Connecting to IPC server" );
ipc_client_t* client = ipc_client_connect( PIPE_NAME );
if( client ) {
BOOL installation_in_progress = FALSE;
LOG_INFO( "Connected" );
char command[ 512 ];
sprintf( command, "msi %s", installer_filename );
LOG_INFO( "Sending command: \"%s\"", command );
if( ipc_client_send( client, command ) ) {
LOG_INFO( "Command sent" );
char response[ 256 ];
char response[ 256 ] = { 0 };
int size = 0;
int temp_size = 0;
LOG_INFO( "Receiving response" );
@ -155,8 +166,8 @@ int main( int argc, char** argv ) {
response[ size ] = '\0';
LOG_INFO( "Response received: \"%s\"", response );
if( strcmp( response, "OK" ) == 0 ) {
LOG_INFO( "Installation successful" );
installation_successful = TRUE;
LOG_INFO( "Installation in progress" );
installation_in_progress = TRUE;
} else {
LOG_ERROR( "Installation failed" );
}
@ -164,14 +175,32 @@ int main( int argc, char** argv ) {
LOG_ERROR( "Failed to send command" );
}
// retrieve logs
LOG_INFO( "Retrieving logs from service" );
bool logs_finished = false;
while( !logs_finished ) {
LOG_INFO( "Sending command: \"log\"" );
if( ipc_client_send( client, "log" ) ) {
// Service will shut down while installation is in progress, so we need to reconnect
if( installation_in_progress ) {
ipc_client_disconnect( client );
client = NULL;
LOG_INFO( "Attempting to reconnect" );
int time_elapsed_ms = 0;
while( !client ) {
Sleep( 5000 );
client = ipc_client_connect( PIPE_NAME );
if( !client ) {
time_elapsed_ms += 5000;
if( time_elapsed_ms > 10*60*1000 ) {
LOG_ERROR( "Unable to reconnect to service after 10 minutes, things have gone very wrong" );
break;
}
}
}
}
if( client ) {
// retrieve status
LOG_INFO( "Retrieving installation status from service" );
LOG_INFO( "Sending command: \"status\"" );
if( ipc_client_send( client, "status" ) ) {
LOG_INFO( "Command sent" );
char response[ 256 ];
char response[ 256 ] = { 0 };
int size = 0;
int temp_size = 0;
LOG_INFO( "Receiving response" );
@ -187,22 +216,68 @@ int main( int argc, char** argv ) {
}
response[ size ] = '\0';
if( *response ) {
size_t len = strlen( response );
if( len > 0 && response[ len - 1 ] == '\n' ) {
response[ len - 1 ] = '\0';
if( stricmp( response, "FINISHED" ) == 0 ) {
LOG_INFO( "INSTALLATION SUCCESSFUL" );
installation_successful = TRUE;
} else if( stricmp( response, "FAILED" ) == 0 ) {
LOG_ERROR( "FAILED TO LAUNCH INSTALLER" );
} else if( stricmp( response, "INVALID" ) == 0 ) {
LOG_ERROR( "NO RECENT INSTALLATION" );
}
LOG_INFO( "SERVER LOG | %s", response );
} else {
LOG_INFO( "All logs retrieved" );
logs_finished = true;
LOG_ERROR( "Failed to get a valid status response" );
ipc_client_disconnect( client );
client = NULL;
}
} else {
LOG_ERROR( "Failed to send command" );
LOG_ERROR( "Failed to send command, disconnecting and aborting. Logs not collected." );
ipc_client_disconnect( client );
client = NULL;
}
// retrieve logs
if( client ) {
LOG_INFO( "Retrieving logs from service" );
bool logs_finished = false;
while( !logs_finished ) {
LOG_INFO( "Sending command: \"log\"" );
if( ipc_client_send( client, "log" ) ) {
LOG_INFO( "Command sent" );
char response[ 4096 ] = { 0 };
int size = 0;
int temp_size = 0;
LOG_INFO( "Receiving response" );
ipc_receive_status_t status = IPC_RECEIVE_STATUS_MORE_DATA;
while( size < sizeof( response ) - 1 && status == IPC_RECEIVE_STATUS_MORE_DATA ) {
status = ipc_client_receive( client, response + size,
sizeof( response ) - size - 1, &temp_size );
if( status == IPC_RECEIVE_STATUS_ERROR ) {
LOG_ERROR( "Receiving response failed" );
break;
}
size += temp_size;
}
response[ size ] = '\0';
if( *response ) {
size_t len = strlen( response );
if( len > 0 && response[ len - 1 ] == '\n' ) {
response[ len - 1 ] = '\0';
}
LOG_INFO( "SERVER LOG | %s", response );
} else {
LOG_INFO( "All logs retrieved" );
logs_finished = true;
}
} else {
LOG_ERROR( "Failed to send command, disconnecting and aborting. Logs not collected." );
ipc_client_disconnect( client );
client = NULL;
}
}
LOG_INFO( "All done, disconnecting from client" );
ipc_client_disconnect( client );
}
}
LOG_INFO( "All done, disconnecting from client" );
ipc_client_disconnect( client );
}
LOG_INFO( "Launching SDA after installation: \"%s\"", application_filename );

View File

@ -43,6 +43,15 @@ struct { BYTE hash[ 20 ]; } thumbprints[] = {
};
enum install_status_t {
INSTALL_STATUS_NONE,
INSTALL_STATUS_FINISHED,
INSTALL_STATUS_FAILED,
};
enum install_status_t g_status_for_last_install = INSTALL_STATUS_NONE;
// Logging
struct log_entry_t {
@ -61,7 +70,6 @@ struct log_t {
clock_t session_end;
} g_log;
void internal_log( char const* file, int line, char const* func, char const* level, char const* format, ... ) {
EnterCriticalSection( &g_log.mutex );
@ -142,15 +150,19 @@ void internal_log_last_error( char const* file, int line, char const* func, char
#define LOG_LAST_ERROR( message ) internal_log_last_error( __FILE__, __LINE__, __func__, "error", message )
void log_init( void ) {
void log_init( bool usestdout ) {
InitializeCriticalSection( &g_log.mutex );
char path[ MAX_PATH ];
ExpandEnvironmentStringsA( "%LOCALAPPDATA%\\SdaAutoUpdate", path, MAX_PATH );
CreateDirectory( path, NULL );
sprintf( g_log.filename, "%s\\saus_%d.log", path, (int) time( NULL ) );
if( usestdout ) {
g_log.file = stdout;
} else {
char path[ MAX_PATH ];
ExpandEnvironmentStringsA( "%LOCALAPPDATA%\\SdaAutoUpdate", path, MAX_PATH );
CreateDirectory( path, NULL );
sprintf( g_log.filename, "%s\\saus_%d.log", path, (int) time( NULL ) );
g_log.file = fopen( g_log.filename, "w" );
g_log.file = fopen( g_log.filename, "w" );
}
time_t rawtime = time( NULL );
struct tm* ptm = gmtime( &rawtime );
@ -164,6 +176,17 @@ void log_init( void ) {
}
void retrieve_status( char* response, size_t capacity ) {
if( g_status_for_last_install == INSTALL_STATUS_FINISHED ) {
strcpy( response, "FINISHED" );
} else if( g_status_for_last_install == INSTALL_STATUS_FAILED ) {
strcpy( response, "FAILED" );
} else {
strcpy( response, "INVALID" );
}
}
void retrieve_buffered_log_line( char* response, size_t capacity ) {
EnterCriticalSection( &g_log.mutex );
if( g_log.session_end == 0 ) {
@ -406,6 +429,31 @@ BOOL validate_installer( char const* filename ) {
}
void merge_msiexec_log( char const* logfile ) {
wchar_t wlogfile[ MAX_PATH ];
MultiByteToWideChar( CP_ACP, 0, logfile, -1, wlogfile, sizeof( wlogfile ) / sizeof( *wlogfile ) );
FILE* fp = _wfopen( wlogfile, L"r, ccs=UTF-16LE");
if( !fp ) {
LOG_ERROR( "Failed to read msiexec log file" );
}
fseek( fp, 2, SEEK_SET );
static wchar_t wline[ 4096 ] = { 0 };
static char line[ 4096 ] = { 0 };
while( fgetws( wline, sizeof( wline ) / sizeof( *wline ), fp ) != NULL ) {
WideCharToMultiByte( CP_ACP, 0, (wchar_t*) wline, -1, line, sizeof( line ), NULL, NULL );
size_t len = strlen( line );
if( len > 0 ) {
char* end = ( line + len ) - 1;
if( *end == '\n' ) *end = '\0';
}
LOG_INFO( "MSIEXEC: %s", line );
memset( wline, 0, sizeof( wline ) );
memset( line, 0, sizeof( line ) );
}
fclose( fp );
}
// Runs msiexec with the supplied filename
bool run_installer( char const* filename ) {
// Reject installers which are not signed with a Symphony certificate
@ -415,8 +463,12 @@ bool run_installer( char const* filename ) {
}
LOG_INFO( "Signature of installer successfully validated" );
char logfile[ MAX_PATH ];
ExpandEnvironmentStringsA( "%LOCALAPPDATA%\\SdaAutoUpdate\\msiexec.log", logfile, MAX_PATH );
DeleteFileA( logfile );
char command[ 512 ];
sprintf( command, "/i %s /q", filename );
sprintf( command, "/i %s /q LAUNCH_ON_INSTALL=\"false\" /l*v \"%s\" ", filename, logfile );
LOG_INFO( "MSI command: %s", command );
SHELLEXECUTEINFO ShExecInfo = { 0 };
@ -429,7 +481,16 @@ bool run_installer( char const* filename ) {
ShExecInfo.lpDirectory = NULL;
ShExecInfo.nShow = SW_SHOW;
ShExecInfo.hInstApp = NULL;
char statusfile[ MAX_PATH ];
ExpandEnvironmentStringsA( "%LOCALAPPDATA%\\SdaAutoUpdate\\status.sau", statusfile, MAX_PATH );
FILE* fp = fopen( statusfile, "w" );
fprintf( fp, "PENDING" );
fclose( fp );
if( ShellExecuteEx( &ShExecInfo ) ) {
fp = fopen( statusfile, "w" );
fprintf( fp, "SUCCESS" );
fclose( fp );
LOG_INFO( "ShellExecuteEx successful, waiting to finish" );
WaitForSingleObject( ShExecInfo.hProcess, INFINITE );
LOG_INFO( "ShellExecuteEx finished" );
@ -437,8 +498,11 @@ bool run_installer( char const* filename ) {
GetExitCodeProcess( ShExecInfo.hProcess, &exitCode );
LOG_INFO( "ShellExecuteEx exit code: %d", exitCode );
CloseHandle( ShExecInfo.hProcess );
merge_msiexec_log( logfile );
return exitCode == 0 ? true : false;
} else {
DeleteFileA( statusfile );
g_status_for_last_install = INSTALL_STATUS_FAILED;
LOG_LAST_ERROR( "Failed to run installer" );
return false;
}
@ -468,6 +532,11 @@ void ipc_handler( char const* request, void* user_data, char* response, size_t c
LOG_INFO( "Response: ERROR" );
strcpy( response, "ERROR" );
}
} else if( strlen( request ) == 6 && stricmp( request, "status" ) == 0 ) {
// "status" - return result of last install
LOG_INFO( "STATUS command, reading status file" );
retrieve_status( response, capacity );
LOG_INFO( "Status: %s", response );
} else if( strlen( request ) == 3 && stricmp( request, "log" ) == 0 ) {
// "log" - send log line
LOG_INFO( "LOG command, returning next log line" );
@ -481,13 +550,26 @@ void ipc_handler( char const* request, void* user_data, char* response, size_t c
// Service main function. Keeps an IPC server running - if it gets disconnected it starts it
// up again. Install requests are handled by ipc_handler above
void service_main( void ) {
void service_main( bool* service_is_running ) {
LOG_INFO( "Service main function running" );
while( service_is_running() ) {
char statusfile[ MAX_PATH ];
ExpandEnvironmentStringsA( "%LOCALAPPDATA%\\SdaAutoUpdate\\status.sau", statusfile, MAX_PATH );
char status[ 32 ] = { 0 };
FILE* fp = fopen( statusfile, "r" );
if( fp ) {
fgets( status, sizeof( status ), fp );
fclose( fp );
}
if( stricmp( status, "PENDING" ) == 0 || stricmp( status, "SUCCESS" ) == 0 ) {
g_status_for_last_install = INSTALL_STATUS_FINISHED;
}
while( *service_is_running ) {
bool is_connected = true;
LOG_INFO( "Starting IPC server" );
ipc_server_t* server = ipc_server_start( PIPE_NAME, ipc_handler, &is_connected );
while( is_connected && service_is_running() ) {
while( is_connected && *service_is_running ) {
service_sleep();
}
LOG_INFO( "IPC server disconnected" );
@ -498,7 +580,11 @@ void service_main( void ) {
int main( int argc, char** argv ) {
log_init();
if( argc >= 2 && stricmp( argv[ 1 ], "test" ) == 0 ) {
log_init( true );
} else {
log_init( false );
}
// Debug helpers for install/uninstall
if( argc >= 2 && stricmp( argv[ 1 ], "install" ) == 0 ) {
@ -519,6 +605,11 @@ int main( int argc, char** argv ) {
return EXIT_FAILURE;
}
}
if( argc >= 2 && stricmp( argv[ 1 ], "test" ) == 0 ) {
// run the ipc server as a normal exe, not as an installed service, for faster turnaround and debugging when testing
bool running = true;
return service_main( &running );
}
// Run the service - called by the Windows Services system
LOG_INFO( "Starting service" );

View File

@ -4,7 +4,7 @@
#include <stdbool.h>
#include <stddef.h>
#define IPC_MESSAGE_MAX_LENGTH 512
#define IPC_MESSAGE_MAX_LENGTH 4096
// client

View File

@ -6,12 +6,10 @@
bool service_install( char const* service_name );
bool service_uninstall( char const* service_name );
typedef void (*service_main_func_t)( void );
typedef void (*service_main_func_t)( bool* is_running );
void service_run( char const* service_name, service_main_func_t main_func );
bool service_is_running( void );
void service_sleep( void );
void service_cancel_sleep( void );
@ -146,7 +144,7 @@ struct {
// Thread proc for service. Just calls the user-provided main func
DWORD WINAPI service_main_thread( LPVOID param ) {
SERVICE_LOG_INFO( "Starting service main thread" );
g_service.main_func();
g_service.main_func( (bool*) param );
SERVICE_LOG_INFO( "Terminating service main thread" );
return EXIT_SUCCESS;
}
@ -248,7 +246,7 @@ VOID WINAPI service_proc( DWORD argc, LPSTR *argv ) {
NULL, // no security attribute
0, // default stack size
service_main_thread, // thread proc
NULL, // thread parameter
&g_service.is_running, // thread parameter
0, // not suspended
NULL ); // returns thread ID
@ -277,7 +275,7 @@ VOID WINAPI service_proc( DWORD argc, LPSTR *argv ) {
// Run the service with the specified name, and invoke the main_func function
// The main_func provided should exit if service_is_running returns false
// The main_func provided should exit if is_running becomes false
void service_run( char const* service_name, service_main_func_t main_func ) {
SetLastError( 0 );
SERVICE_LOG_INFO( "Starting service" );
@ -307,12 +305,6 @@ void service_run( char const* service_name, service_main_func_t main_func ) {
}
// Returns true while service is running, false if it has been asked to stop
bool service_is_running() {
return g_service.is_running;
}
// Sleeps until service_cancel_sleep is called, either manually by the user or
// because the serice received a stop request
void service_sleep( void ) {