From ee10e4887bb6651f7e59c32f8be09325b08e3533 Mon Sep 17 00:00:00 2001 From: Simon Rettberg Date: Mon, 23 Feb 2015 14:18:07 +0100 Subject: [SERVER] printf -> logadd, make USR2 trigger a log cycle, remove old fake delay feature --- server.config.example/server.conf | 1 + src/server/altservers.c | 3 ++- src/server/image.c | 45 ++++++++++++++++---------------- src/server/net.c | 3 --- src/server/server.c | 54 +++++++++++++++------------------------ src/server/server.h | 4 --- src/server/sockhelper.c | 12 ++++----- src/server/uplink.c | 6 ++--- 8 files changed, 54 insertions(+), 74 deletions(-) diff --git a/server.config.example/server.conf b/server.config.example/server.conf index 3e5aa8c..8ac942d 100644 --- a/server.config.example/server.conf +++ b/server.config.example/server.conf @@ -17,6 +17,7 @@ clientTimeout=15000 ; Log related config [logging] ; log file path and name +; protip: use SIGUSR2 to reopen log file file=./dnbd3.log ; which type of messages to log to file fileMask=ERROR WARNING MINOR INFO DEBUG1 diff --git a/src/server/altservers.c b/src/server/altservers.c index 7ebe36b..f281395 100644 --- a/src/server/altservers.c +++ b/src/server/altservers.c @@ -7,6 +7,7 @@ #include "globals.h" #include "image.h" #include "signal.h" +#include "log.h" #include #include #include @@ -491,7 +492,7 @@ static void *altservers_main(void *data UNUSED) // Done testing all servers. See if we should switch if ( bestSock != -1 && (uplink->fd == -1 || (bestRtt < 10000000 && RTT_THRESHOLD_FACTOR(currentRtt) > bestRtt)) ) { // yep - printf( "DO CHANGE: best: %uµs, current: %uµs\n", bestRtt, currentRtt ); + logadd( LOG_DEBUG1, "Change @ %s - best: %uµs, current: %uµs\n", image->lower_name, bestRtt, currentRtt ); uplink->betterFd = bestSock; uplink->betterServer = servers[bestIndex]; uplink->rttTestResult = RTT_DOCHANGE; diff --git a/src/server/image.c b/src/server/image.c index bf8c3a6..b86ecf3 100644 --- a/src/server/image.c +++ b/src/server/image.c @@ -1009,29 +1009,29 @@ bool image_generateCrcFile(char *image) { int fdImage = open( image, O_RDONLY ); if ( fdImage < 0 ) { - printf( "Could not open %s.\n", image ); + logadd( LOG_ERROR, "Could not open %s.", image ); return false; } -// force size to be multiple of DNBD3_BLOCK_SIZE + // force size to be multiple of DNBD3_BLOCK_SIZE int64_t fileLen = lseek( fdImage, 0, SEEK_END ); if ( fileLen <= 0 ) { - printf( "Error seeking to end, or file is empty.\n" ); + logadd( LOG_ERROR, "Error seeking to end, or file is empty." ); close( fdImage ); return false; } if ( fileLen % DNBD3_BLOCK_SIZE != 0 ) { - printf( "File length is not a multiple of DNBD3_BLOCK_SIZE\n" ); + logadd( LOG_WARNING, "File length is not a multiple of DNBD3_BLOCK_SIZE" ); const int64_t ret = image_pad( image, fileLen ); if ( ret < fileLen ) { - printf( "Error appending to file in order to make it block aligned.\n" ); + logadd( LOG_ERROR, "Error appending to file in order to make it block aligned." ); close( fdImage ); return false; } - printf( "...fixed!\n" ); + logadd( LOG_INFO, "...fixed!" ); fileLen = ret; } if ( lseek( fdImage, 0, SEEK_SET ) != 0 ) { - printf( "Seeking back to start failed.\n" ); + logadd( LOG_ERROR, "Seeking back to start failed." ); close( fdImage ); return false; } @@ -1039,19 +1039,19 @@ bool image_generateCrcFile(char *image) sprintf( crcFile, "%s.crc", image ); struct stat sst; if ( stat( crcFile, &sst ) == 0 ) { - printf( "CRC File for %s already exists! Delete it first if you want to regen.\n", image ); + logadd( LOG_ERROR, "CRC File for %s already exists! Delete it first if you want to regen.", image ); close( fdImage ); return false; } int fdCrc = open( crcFile, O_RDWR | O_CREAT, 0644 ); if ( fdCrc < 0 ) { - printf( "Could not open CRC File %s for writing..\n", crcFile ); + logadd( LOG_ERROR, "Could not open CRC File %s for writing..", crcFile ); close( fdImage ); return false; } // CRC of all CRCs goes first. Don't know it yet, write 4 bytes dummy data. if ( write( fdCrc, crcFile, 4 ) != 4 ) { - printf( "Write error\n" ); + logadd( LOG_ERROR, "Write error" ); close( fdImage ); close( fdCrc ); return false; @@ -1092,17 +1092,18 @@ bool image_generateCrcFile(char *image) close( fdCrc ); return false; } - printf( "." ); + putchar( '.' ); fflush( stdout ); blocksToGo++; } } while ( !finished ); close( fdImage ); - printf( "done!\nGenerating master-crc..." ); + printf( "done!" ); + logadd( LOG_INFO, "Generating master-crc..." ); fflush( stdout ); // File is written - read again to calc master crc if ( lseek( fdCrc, 4, SEEK_SET ) != 4 ) { - printf( "Could not seek to beginning of crc list in file\n" ); + logadd( LOG_ERROR, "Could not seek to beginning of crc list in file" ); close( fdCrc ); return false; } @@ -1110,7 +1111,7 @@ bool image_generateCrcFile(char *image) while ( blocksToGo > 0 ) { const int numBlocks = MIN(1000, blocksToGo); if ( read( fdCrc, buffer, numBlocks * 4 ) != numBlocks * 4 ) { - printf( "Could not re-read from crc32 file\n" ); + logadd( LOG_ERROR, "Could not re-read from crc32 file" ); close( fdCrc ); return false; } @@ -1118,16 +1119,16 @@ bool image_generateCrcFile(char *image) blocksToGo -= numBlocks; } if ( lseek( fdCrc, 0, SEEK_SET ) != 0 ) { - printf( "Could not seek back to beginning of crc32 file\n" ); + logadd( LOG_ERROR, "Could not seek back to beginning of crc32 file" ); close( fdCrc ); return false; } if ( write( fdCrc, &crc, 4 ) != 4 ) { - printf( "Could not write master crc to file\n" ); + logadd( LOG_ERROR, "Could not write master crc to file" ); close( fdCrc ); return false; } - printf( "..done!\nCRC-32 file successfully generated.\n" ); + logadd( LOG_INFO, "CRC-32 file successfully generated." ); fflush( stdout ); return true; } @@ -1140,9 +1141,9 @@ void image_printAll() for (i = 0; i < _num_images; ++i) { if ( _images[i] == NULL ) continue; spin_lock( &_images[i]->lock ); - printf( "Image: %s\n", _images[i]->lower_name ); + logadd( LOG_DEBUG1, "Image: %s", _images[i]->lower_name ); percent = image_getCompletenessEstimate( _images[i] ); - printf( " Complete: %d%%\n", percent ); + logadd( LOG_DEBUG1, " |- Complete: %d%%", percent ); if ( _images[i]->uplink != NULL ) { host_to_string( &_images[i]->uplink->currentServer, buffer, sizeof(buffer) ); pending = 0; @@ -1151,9 +1152,9 @@ void image_printAll() if ( _images[i]->uplink->queue[j].status != ULR_FREE ) pending++; } spin_unlock( &_images[i]->uplink->queueLock ); - printf( " Uplink: %s -- %d pending requests\n", buffer, pending ); + logadd( LOG_DEBUG1, " |- Uplink: %s -- %d pending requests", buffer, pending ); } - printf( " Users: %d\n", _images[i]->users ); + logadd( LOG_DEBUG1, " `- Users: %d\n", _images[i]->users ); spin_unlock( &_images[i]->lock ); } spin_unlock( &_images_lock ); @@ -1207,7 +1208,7 @@ bool image_checkBlocksCrc32(int fd, uint32_t *crc32list, const int *blocks, cons readPos += r; } if ( crc != crc32list[*blocks] ) { - printf( "Block %d is %x, should be %x\n", *blocks, crc, crc32list[*blocks] ); + logadd( LOG_WARNING, "Block %d is %x, should be %x", *blocks, crc, crc32list[*blocks] ); return false; } blocks++; diff --git a/src/server/net.c b/src/server/net.c index 1d30183..3046795 100644 --- a/src/server/net.c +++ b/src/server/net.c @@ -67,9 +67,6 @@ static inline bool recv_request_header(int sock, dnbd3_request_t *request) (int)request->size ); return false; } -#ifdef _DEBUG - if ( _fake_delay ) usleep( _fake_delay ); -#endif return true; } diff --git a/src/server/server.c b/src/server/server.c index 77619eb..0547a87 100644 --- a/src/server/server.c +++ b/src/server/server.c @@ -47,9 +47,6 @@ #include "threadpool.h" poll_list_t *listeners = NULL; -#ifdef _DEBUG -int _fake_delay = 0; -#endif dnbd3_client_t *_clients[SERVER_MAX_CLIENTS]; int _num_clients = 0; @@ -59,7 +56,7 @@ pthread_spinlock_t _clients_lock; * Time the server was started */ static time_t startupTime = 0; -static bool sigReload = false, sigPrintStats = false; +static bool sigReload = false, sigLogCycle = false; static bool dnbd3_addClient(dnbd3_client_t *client); static void dnbd3_handleSignal(int signum); @@ -73,10 +70,7 @@ void dnbd3_printHelp(char *argv_0) printf( "Version: %s\n\n", VERSION_STRING ); printf( "Usage: %s [OPTIONS]...\n", argv_0 ); printf( "Start the DNBD3 server\n" ); - printf( "-c or --config Configuration file (default /etc/dnbd3-server.conf)\n" ); -#ifdef _DEBUG - printf( "-d or --delay Add a fake network delay of X µs\n" ); -#endif + printf( "-c or --config Configuration directory (default /etc/dnbd3-server/)\n" ); printf( "-n or --nodaemon Start server in foreground\n" ); printf( "-b or --bind Local Address to bind to\n" ); //printf( "-r or --reload Reload configuration file\n" ); @@ -84,7 +78,7 @@ void dnbd3_printHelp(char *argv_0) //printf( "-i or --info Print connected clients and used images\n" ); printf( "-h or --help Show this help text and quit\n" ); printf( "-v or --version Show version and quit\n" ); - printf( "Management functions:\n" ); + printf( "\nManagement functions:\n" ); printf( "--crc [image-file] Generate crc block list for given image\n" ); printf( "--create [image-name] --revision [rid] --size [filesize]\n" "\tCreate a local empty image file with a zeroed cache-map for the specified image\n" ); @@ -149,7 +143,7 @@ void dnbd3_cleanup() } spin_unlock( &_clients_lock ); if ( count != 0 ) { - printf( "%d clients still active...\n", count ); + logadd( LOG_INFO, "%d clients still active...\n", count ); sleep( 1 ); } } while ( count != 0 && --retries > 0 ); @@ -158,7 +152,7 @@ void dnbd3_cleanup() // Clean up images retries = 5; while ( !image_tryFreeAll() && --retries > 0 ) { - printf( "Waiting for images to free...\n" ); + logadd( LOG_INFO, "Waiting for images to free...\n" ); sleep( 1 ); } @@ -180,7 +174,6 @@ int main(int argc, char *argv[]) static const char *optString = "c:d:b:nrsihv?"; static const struct option longOpts[] = { { "config", required_argument, NULL, 'c' }, - { "delay", required_argument, NULL, 'd' }, { "nodaemon", no_argument, NULL, 'n' }, { "reload", no_argument, NULL, 'r' }, { "stop", no_argument, NULL, 's' }, @@ -203,31 +196,23 @@ int main(int argc, char *argv[]) case 'c': _configDir = strdup( optarg ); break; - case 'd': - #ifdef _DEBUG - _fake_delay = atoi( optarg ); - break; -#else - printf( "This option is only available in debug builds.\n\n" ); - return EXIT_FAILURE; -#endif case 'n': demonize = 0; break; case 'r': - printf( "INFO: Reloading configuration file...\n\n" ); + logadd( LOG_INFO, "Reloading configuration file..." ); //dnbd3_rpc_send(RPC_RELOAD); return EXIT_SUCCESS; case 's': - printf( "INFO: Stopping running server...\n\n" ); + logadd( LOG_INFO, "Stopping running server..." ); //dnbd3_rpc_send(RPC_EXIT); return EXIT_SUCCESS; case 'i': - printf( "INFO: Requesting information...\n\n" ); + logadd( LOG_INFO, "Requesting information..." ); //dnbd3_rpc_send(RPC_IMG_LIST); return EXIT_SUCCESS; case 'h': - case '?': + case '?': dnbd3_printHelp( argv[0] ); break; case 'v': @@ -261,7 +246,7 @@ int main(int argc, char *argv[]) if ( _configDir == NULL ) _configDir = strdup( "/etc/dnbd3-server" ); globals_loadConfig(); if ( _basePath == NULL ) { - printf( "ERROR: basePath not set in %s/%s\n", _configDir, CONFIG_FILENAME ); + logadd( LOG_ERROR, "basePath not set in %s/%s", _configDir, CONFIG_FILENAME ); exit( EXIT_FAILURE ); } @@ -340,12 +325,13 @@ int main(int argc, char *argv[]) logadd( LOG_INFO, "SIGUSR1 received, re-scanning image directory" ); image_loadAll( NULL ); } - if ( sigPrintStats ) { - sigPrintStats = false; - logadd( LOG_WARNING, " ** Images **" ); - image_printAll(); - logadd( LOG_WARNING, " ** Clients **" ); - dnbd3_printClients(); + if ( sigLogCycle ) { + sigLogCycle = false; + logadd( LOG_INFO, "SIGUSR2 received, reopening log file..." ); + if ( log_openLogFile( NULL ) ) + logadd( LOG_INFO, "Log file has been reopened." ); + else + logadd( LOG_WARNING, "Could not cycle log file." ); } // len = sizeof(client); @@ -491,7 +477,7 @@ static void dnbd3_handleSignal(int signum) } else if ( signum == SIGUSR1 || signum == SIGHUP ) { sigReload = true; } else if ( signum == SIGUSR2 ) { - sigPrintStats = true; + sigLogCycle = true; } } @@ -509,8 +495,8 @@ static void dnbd3_printClients() if ( _clients[i] == NULL ) continue; spin_lock( &_clients[i]->lock ); host_to_string( &_clients[i]->host, buffer, sizeof(buffer) ); - printf( "Client %s\n", buffer ); - if ( _clients[i]->image != NULL ) printf( " Image: %s\n", _clients[i]->image->lower_name ); + logadd( LOG_DEBUG1, "Client %s", buffer ); + if ( _clients[i]->image != NULL ) logadd( LOG_DEBUG1, " `- Image: %s\n", _clients[i]->image->lower_name ); spin_unlock( &_clients[i]->lock ); } spin_unlock( &_clients_lock ); diff --git a/src/server/server.h b/src/server/server.h index 2b10b75..8769540 100644 --- a/src/server/server.h +++ b/src/server/server.h @@ -34,10 +34,6 @@ extern dnbd3_client_t *_clients[SERVER_MAX_CLIENTS]; extern int _num_clients; extern pthread_spinlock_t _clients_lock; -#ifdef _DEBUG -extern int _fake_delay; -#endif - void dnbd3_cleanup(); void dnbd3_removeClient(dnbd3_client_t *client); dnbd3_client_t* dnbd3_freeClient(dnbd3_client_t *client); diff --git a/src/server/sockhelper.c b/src/server/sockhelper.c index fbde74c..e45efba 100644 --- a/src/server/sockhelper.c +++ b/src/server/sockhelper.c @@ -115,25 +115,24 @@ bool sock_listen(poll_list_t* list, char* bind_addr, uint16_t port) for( ptr = res; ptr != NULL; ptr = ptr->ai_next ) { char bla[100]; if ( !sock_printable( (struct sockaddr*)ptr->ai_addr, ptr->ai_addrlen, bla, 100 ) ) snprintf( bla, 100, "[invalid]" ); - printf( "Trying to bind to %s ", bla ); + logadd( LOG_DEBUG1, "Binding to %s...", bla ); int sock = socket( ptr->ai_family, ptr->ai_socktype, ptr->ai_protocol ); if ( sock < 0 ) { - printf( "...cannot socket(), errno=%d\n", errno ); + logadd( LOG_WARNING, "(Bind to %s): cannot socket(), errno=%d", bla, errno ); continue; } setsockopt( sock, SOL_SOCKET, SO_REUSEADDR, &on, sizeof(on) ); if ( ptr->ai_family == PF_INET6 ) setsockopt( sock, IPPROTO_IPV6, IPV6_V6ONLY, &on, sizeof(on) ); if ( bind( sock, ptr->ai_addr, ptr->ai_addrlen ) == -1 ) { - printf( "...cannot bind(), errno=%d\n", errno ); + logadd( LOG_WARNING, "(Bind to %s): cannot bind(), errno=%d", bla, errno ); close( sock ); continue; } if ( listen( sock, 20 ) == -1 ) { - printf( "...cannot listen(), errno=%d\n", errno ); + logadd( LOG_WARNING, "(Bind to %s): cannot listen(), errno=%d", errno ); close( sock ); continue; } - printf( "...OK!\n" ); list->entry[list->count].fd = sock; list->entry[list->count].events = POLLIN | POLLRDHUP; list->count++; @@ -153,14 +152,13 @@ int sock_accept(poll_list_t *list, struct sockaddr_storage *addr, socklen_t *len { int ret = poll( list->entry, list->count, -1 ); if ( ret < 0 ) { - printf( "poll errno=%d\n", errno ); return -1; } for ( int i = list->count - 1; i >= 0; --i ) { if ( list->entry[i].revents == 0 ) continue; if ( list->entry[i].revents == POLLIN ) return accept( list->entry[i].fd, (struct sockaddr *)addr, length_ptr ); if ( list->entry[i].revents & ( POLLNVAL | POLLHUP | POLLERR | POLLRDHUP ) ) { - printf( "poll fd revents=%d for index=%d and fd=%d\n", (int)list->entry[i].revents, i, list->entry[i].fd ); + logadd( LOG_DEBUG1, "poll fd revents=%d for index=%d and fd=%d", (int)list->entry[i].revents, i, list->entry[i].fd ); if ( ( list->entry[i].revents & POLLNVAL ) == 0 ) close( list->entry[i].fd ); if ( i != list->count ) list->entry[i] = list->entry[list->count]; list->count--; diff --git a/src/server/uplink.c b/src/server/uplink.c index edf8b89..d71daa6 100644 --- a/src/server/uplink.c +++ b/src/server/uplink.c @@ -190,8 +190,8 @@ bool uplink_request(dnbd3_client_t *client, uint64_t handle, uint64_t start, uin if ( foundExisting != -1 && existingType != ULR_NEW && freeSlot > foundExisting ) foundExisting = -1; #ifdef _DEBUG if ( foundExisting != -1 ) { - printf( "%p (%s) Found existing request of type %s at slot %d, attaching in slot %d.\n", (void*)uplink, uplink->image->lower_name, existingType == ULR_NEW ? "ULR_NEW" : "ULR_PENDING", foundExisting, freeSlot ); - printf( "Original %" PRIu64 "-%" PRIu64 " (%p)\n" + logadd( LOG_DEBUG2, "%p (%s) Found existing request of type %s at slot %d, attaching in slot %d.\n", (void*)uplink, uplink->image->lower_name, existingType == ULR_NEW ? "ULR_NEW" : "ULR_PENDING", foundExisting, freeSlot ); + logadd( LOG_DEBUG2, "Original %" PRIu64 "-%" PRIu64 " (%p)\n" "New %" PRIu64 "-%" PRIu64 " (%p)\n", uplink->queue[foundExisting].from, uplink->queue[foundExisting].to, (void*)uplink->queue[foundExisting].client, start, end, (void*)client ); @@ -391,7 +391,7 @@ static void* uplink_mainloop(void *data) link->queue[i].status = ULR_NEW; resend = true; spin_unlock( &link->queueLock ); - printf("%s", buffer); + logadd( LOG_WARNING, "%s", buffer ); spin_lock( &link->queueLock ); } } -- cgit v1.2.3-55-g7522