bool Log::makeNewLogFile ( ) {
// prevent deadlock. don't log since we are in the middle of logging.
// otherwise, safebuf, which is used when renaming files, might
// call logR().
g_loggingEnabled = false;
// . rename old log file like log000 to log000-2013_11_04-18:19:32
// . returns false on error
bool status = renameCurrentLogFile();
// re-enable logging since nothing below should call logR() indirectly
g_loggingEnabled = true;
if ( ! status ) return false;
// close old fd
if ( m_fd >= 0 ) ::close ( m_fd );
// invalidate
m_fd = -1;
// reset
m_logFileSize = 0;
// open it for appending.
// create with -rw-rw-r-- permissions if it's not there.
m_fd = open ( m_filename ,
O_APPEND | O_CREAT | O_RDWR ,
getFileCreationFlags() );
if ( m_fd >= 0 ) return true;
// bitch to stderr and return false on error
fprintf(stderr,"could not open new log file %s for appending\n",
m_filename);
return false;
}
bool Log::init ( const char *filename ) {
// init these
m_fd = -1;
m_disabled = false;
// is there a filename to log our errors to?
m_filename = filename;
if ( ! m_filename ) return true;
//
// RENAME log000 to log000-20131104-181932
//
if ( g_conf.m_logToFile ) {
// returns false on error
if ( ! renameCurrentLogFile() ) return false;
}
// get size of current file. getFileSize() is defined in File.h.
m_logFileSize = getFileSize ( m_filename );
if ( strcmp(m_filename,"/dev/stderr") == 0 ) {
m_fd = STDERR_FILENO; // 2; // stderr
return true;
}
// open it for appending.
// create with -rw-rw-r-- permissions if it's not there.
m_fd = open ( m_filename ,
O_APPEND | O_CREAT | O_RDWR ,
getFileCreationFlags() );
if ( m_fd >= 0 ) return true;
// bitch to stderr and return false on error
fprintf(stderr,"could not open log file %s for appending\n",
m_filename);
return false;
}
void handleRequest ( UdpSlot *slot , int32_t netnice ) {
char *p = slot->m_readBuf;
int32_t numBytes = *(int32_t*)p;
p += sizeof(int32_t);
char *filename = g_hostdb.m_logFilename;
// running just ./gb will log to stderr...
if ( strcmp(filename ,"/dev/stderr") == 0 ) {
g_errno = EBADFILE;
log(LOG_ERROR,"%s:%s:%d: call sendErrorReply.", __FILE__, __func__, __LINE__);
g_udpServer.sendErrorReply ( slot, g_errno );
return;
}
int32_t fd = open ( filename , O_RDONLY ,
getFileCreationFlags() );
// S_IRUSR |S_IWUSR |S_IRGRP |S_IWGRP| S_IROTH );
if ( ! fd ) {
log(LOG_DEBUG, "logviewer: Failed to open %s for reading: ",
filename);
g_errno = EBADFILE;
log(LOG_ERROR,"%s:%s:%d: call sendErrorReply.", __FILE__, __func__, __LINE__);
g_udpServer.sendErrorReply ( slot, g_errno );
return;
}
char stackSpace[LOG_WINDOW];
char *buf = stackSpace;
char *allocBuf = NULL;
int32_t allocBufSize = 0;
if(numBytes > LOG_WINDOW) {
buf = (char*)mmalloc(numBytes, "Msg1fA");
if(!buf) {
log(LOG_INFO,
"admin: malloc of %" PRId32" bytes failed "
"for logview,"
" falling back on stack buffer.",
numBytes);
buf = stackSpace;
numBytes = LOG_WINDOW;
}
else {
allocBuf = buf;
allocBufSize = numBytes;
}
}
lseek(fd, -1 * numBytes, SEEK_END);
if(errno == EINVAL) {
//oops! we seeked to before the begining of the file
//log(LOG_WARN, "bad seek!");
lseek(fd, 0, SEEK_SET);
}
int32_t numRead = read(fd, buf, numBytes-1);
close(fd);
if(numRead > 0) buf[numRead-1] = '\0';
else {
buf[0] = '\0';
numRead = 0;
if(allocBuf) mfree(allocBuf, allocBufSize, "Msg1fA");
allocBufSize = 0;
allocBuf = NULL;
log(LOG_ERROR,"%s:%s:%d: call sendErrorReply.", __FILE__, __func__, __LINE__);
g_udpServer.sendErrorReply ( slot, EBADFILE );
return;
}
//log(LOG_DEBUG, "bytes read! %" PRId32" ", numRead);
g_udpServer.sendReply_ass (buf, numRead, allocBuf,allocBufSize, slot); //send
}
void Images::thumbStart_r ( bool amThread ) {
int64_t start = gettimeofdayInMilliseconds();
//static char scmd[200] = "%stopnm %s | "
// "pnmscale -xysize 100 100 - | "
// "ppmtojpeg - > %s";
log( LOG_DEBUG, "image: thumbStart_r entered." );
//DIR *d;
//char cmd[2500];
//sprintf( cmd, "%strash", g_hostdb.m_dir );
makeTrashDir();
// get thread id. pthread_t is 64 bit and pid_t is 32 bit on
// 64 bit oses
pthread_t id = pthread_self();
// pass the input to the program through this file
// rather than a pipe, since popen() seems broken.
// m_dir ends in / so this should work.
char in[364];
snprintf ( in , 363,"%strash/in.%" PRId64
, g_hostdb.m_dir, (int64_t)id );
unlink ( in );
log( LOG_DEBUG, "image: thumbStart_r create in file." );
// collect the output from the filter from this file
// m_dir ends in / so this should work.
char out[364];
snprintf ( out , 363,"%strash/out.%" PRId64
, g_hostdb.m_dir, (int64_t)id );
unlink ( out );
log( LOG_DEBUG, "image: thumbStart_r create out file." );
// ignore errno from those unlinks
errno = 0;
// Open/Create temporary file to store image to
int fhndl;
if( (fhndl = open( in, O_RDWR+O_CREAT ,
getFileCreationFlags()
// // S_IWUSR+S_IRUSR
)) < 0 ) {
log( "image: Could not open file, %s, for writing: %s - %d.",
in, mstrerror( m_errno ), fhndl );
m_imgDataSize = 0;
return;
}
// Write image data into temporary file
if( write( fhndl, m_imgData, m_imgDataSize ) < 0 ) {
log( "image: Could not write to file, %s: %s.",
in, mstrerror( m_errno ) );
close( fhndl );
unlink( in );
m_imgDataSize = 0;
return;
}
// Close temporary image file now that we have finished writing
if( close( fhndl ) < 0 ) {
log( "image: Could not close file, %s, for writing: %s.",
in, mstrerror( m_errno ) );
unlink( in );
m_imgDataSize = 0;
return;
}
fhndl = 0;
// Grab content type from mime
//int32_t imgType = mime.getContentType();
char ext[5];
switch( m_imgType ) {
case CT_GIF:
strcpy( ext, "gif" );
break;
case CT_JPG:
strcpy( ext, "jpeg" );
break;
case CT_PNG:
strcpy( ext, "png" );
break;
case CT_TIFF:
strcpy( ext, "tiff" );
break;
case CT_BMP:
strcpy( ext, "bmp" );
break;
}
// i hope 2500 is big enough!
char cmd[2501];
//sprintf( cmd, scmd, ext, in, out);
char *wdir = g_hostdb.m_dir;
// can be /dev/stderr or like /var/gigablast/data/log000 etc.
const char *logFile = g_log.getFilename();
// wdir ends in / so this should work.
snprintf( cmd, 2500 ,
"LD_LIBRARY_PATH=%s %s%stopnm %s 2>> %s | "
"LD_LIBRARY_PATH=%s %spnmscale -xysize %" PRId32" %" PRId32" - 2>> %s | "
// put all its stderr msgs into /dev/null
// so "jpegtopnm: WRITING PPM FILE" doesn't clog console
"LD_LIBRARY_PATH=%s %sppmtojpeg - > %s 2>> %s"
, wdir , wdir , ext , in , logFile
, wdir , wdir , m_xysize , m_xysize , logFile
, wdir , wdir , out , logFile
);
// if they already have netpbm package installed use that then
static bool s_checked = false;
static bool s_hasNetpbm = false;
if ( ! s_checked ) {
s_checked = true;
File f;
f.set("/usr/bin/pnmscale");
s_hasNetpbm = f.doesExist() ;
}
if ( s_hasNetpbm )
snprintf( cmd, 2500 ,
"%stopnm %s 2>> %s | "
"pnmscale -xysize %" PRId32" %" PRId32" - 2>> %s | "
"ppmtojpeg - > %s 2>> %s"
, ext , in , logFile
, m_xysize , m_xysize , logFile
, out , logFile
);
// Call clone function for the shell to execute command
int err = system( cmd ); // m_thmbconvTimeout );
//if( (m_dx != 0) && (m_dy != 0) )
// unlink( in );
unlink ( in );
if ( err == 127 ) {
m_errno = EBADENGINEER;
log("image: /bin/sh does not exist.");
unlink ( out );
m_stopDownloading = true;
return;
}
// this will happen if you don't upgrade glibc to 2.2.4-32 or above
if ( err != 0 ) {
m_errno = EBADENGINEER;
log("image: Call to system(\"%s\") had error.",cmd);
unlink ( out );
m_stopDownloading = true;
return;
}
// Open new file with thumbnail image
if( (fhndl = open( out, O_RDONLY )) < 0 ) {
log( "image: Could not open file, %s, for reading: %s.",
out, mstrerror( m_errno ) );
unlink ( out );
m_stopDownloading = true;
return;
}
if( (m_thumbnailSize = lseek( fhndl, 0, SEEK_END )) < 0 ) {
log( "image: Seek of file, %s, returned invalid size: %" PRId32,
out, m_thumbnailSize );
m_stopDownloading = true;
close(fhndl);
unlink ( out );
return;
}
if( m_thumbnailSize > m_imgReplyMaxLen ) {
log(LOG_DEBUG,"image: Image thumbnail larger than buffer!" );
log(LOG_DEBUG,"image: File Read Bytes: %" PRId32, m_thumbnailSize);
log(LOG_DEBUG,"image: Buf Max Bytes : %" PRId32,m_imgReplyMaxLen );
log(LOG_DEBUG,"image: -----------------------" );
log(LOG_DEBUG,"image: Diff : %" PRId32,
m_imgReplyMaxLen-m_thumbnailSize );
close(fhndl);
unlink ( out );
return;
}
if( lseek( fhndl, 0, SEEK_SET ) < 0 ) {
log( "image: Seek couldn't rewind file, %s.", out );
m_stopDownloading = true;
close(fhndl);
unlink ( out );
return;
}
// . Read contents back into image ptr
// . this is somewhat of a hack since it overwrites the original img
if( (m_thumbnailSize = read( fhndl, m_imgData, m_imgDataSize )) < 0 ) {
log( "image: Could not read from file, %s: %s.",
out, mstrerror( m_errno ) );
close( fhndl );
m_stopDownloading = true;
unlink( out );
return;
}
if( close( fhndl ) < 0 ) {
log( "image: Could not close file, %s, for reading: %s.",
out, mstrerror( m_errno ) );
unlink( out );
m_stopDownloading = true;
unlink ( out );
return;
}
fhndl = 0;
unlink( out );
int64_t stop = gettimeofdayInMilliseconds();
// tell the loop above not to download anymore, we got one
m_thumbnailValid = true;
// MDW: this was m_imgReply
getImageInfo ( m_imgData , m_thumbnailSize , &m_tdx , &m_tdy , NULL );
// now make the meta data struct
// <imageUrl>\0<width><height><thumbnailData>
log( LOG_DEBUG, "image: Thumbnail size: %" PRId32" bytes.", m_imgDataSize );
log( LOG_DEBUG, "image: Thumbnail dx=%" PRId32" dy=%" PRId32".", m_tdx,m_tdy );
log( LOG_DEBUG, "image: Thumbnail generated in %" PRId64"ms.", stop-start );
}
// . get the fd of this file
// . if it was closed by us we reopen it
// . may re-open a virtual fd whose real fd was closed
// . if we hit our max # of real fds allowed we'll have to close
// the least used of those so we can open this one
// . return -2 if never been opened
// . return -1 on other errors
// . otherwise, return the file descriptor
int File::getfd () {
// if m_vfd is -1 it's never been opened
if ( ! m_calledOpen ) { // m_vfd < 0 ) {
g_errno = EBADENGINEER;
log(LOG_LOGIC,"disk: getfd: Must call open() first.");
char *xx=NULL; *xx=0;
return -2;
}
// if someone closed our fd, why didn't our m_fd get set to -1 ??!?!?!!
if ( m_fd >= 0 && m_closeCount != s_closeCounts[m_fd] ) {
log(LOG_DEBUG,"disk: invalidating existing fd %i "
"for %s this=0x%"PTRFMT" ccSaved=%i ccNow=%i",
(int)m_fd,getFilename(),(PTRTYPE)this,
(int)m_closeCount,
(int)s_closeCounts[m_fd]);
m_fd = -1;
}
// . sanity check
// . no caller should call open/getfd after unlink was queued for thred
//if ( m_gone ) { char *xx = NULL; *xx = 0; }
// get the real fd from the virtual fd
//int fd = s_fds [ m_vfd ];
// return true if it's already opened
if ( m_fd >= 0 ) {
// debug msg
if ( g_conf.m_logDebugDisk )
log(LOG_DEBUG,"disk: returning existing fd %i for %s "
"this=0x%"PTRFMT" ccSaved=%i ccNow=%i",
(int)m_fd,getFilename(),(PTRTYPE)this,
(int)m_closeCount,
(int)s_closeCounts[m_fd]);
if ( m_fd >= MAX_NUM_FDS ) { char *xx=NULL;*xx=0; }
// but update the timestamp to reduce chance it closes on us
//s_timestamps [ m_vfd ] = getTime();
s_timestamps [ m_fd ] = gettimeofdayInMillisecondsLocal();
return m_fd;
}
// if fd is -2 it's marked as available
// if ( fd != -1 ) {
// g_errno = EBADENGINEER;
// log (LOG_LOGIC, "disk: getfd: fd is available?!?!" );
// return -2;
// }
// . a real fd of -1 means it's been closed and we gotta reopen it
// . we have to close someone if we don't have enough room
while ( s_numOpenFiles >= s_maxNumOpenFiles ) {
if ( g_conf.m_logDebugDisk ) sanityCheck();
if ( ! closeLeastUsed() ) return -1;
if ( g_conf.m_logDebugDisk ) sanityCheck();
}
// what was the filename/mode of this timed-out fd?
//char *filename = s_filenames [ m_vfd ];
// time the calls to open just in case they are hurting us
int64_t t1 = -1LL;
// . re-open the sleeping file descriptor
// . if a rename thread was queued or spawned, try old guy first
//if ( m_oldFilename[0] ) {
// t1 = gettimeofdayInMilliseconds();
// fd = ::open ( m_oldFilename , m_flags , m_permissions );
//}
int fd = -1;
// then try to open the new name
if ( fd == -1 ) {
t1 = gettimeofdayInMilliseconds();
retry7:
fd = ::open ( getFilename() , m_flags,getFileCreationFlags());
// valgrind
if ( fd == -1 && errno == EINTR ) goto retry7;
// 0 means stdout, right? why am i seeing it get assigned???
if ( fd == 0 )
log("disk: Got fd of 0 when opening %s.",
getFilename());
if ( fd == 0 )
fd=::open(getFilename(),m_flags,getFileCreationFlags());
if ( fd == 0 )
log("disk: Got fd of 0 when opening2 %s.",
getFilename());
if ( fd >= MAX_NUM_FDS )
log("disk: got fd of %i out of bounds 1 of %i",
(int)fd,(int)MAX_NUM_FDS);
// if we got someone else's fd that called close1_r() in a
// thread but did not have time to call close2() to fix
// up these member vars, then do it here. close2() will
// see that s_filePtrs[fd] does not equal the file ptr any more
// and it will not update s_numOpenFiles in that case.
if ( fd >= 0 && s_open [ fd ] ) {
File *f = s_filePtrs [ fd ];
if ( g_conf.m_logDebugDisk )
log("disk: swiping fd %i from %s before "
"his close thread returned "
"this=0x%"PTRFMT,
fd,
f->getFilename(),
(PTRTYPE)f);
// he only incs/decs his counters if he owns it so in
// close2() so dec this global counter here
s_numOpenFiles--;
s_open[fd] = 0;
s_filePtrs[fd] = NULL;
if ( g_conf.m_logDebugDisk ) sanityCheck();
}
// sanity. how can we get an fd already opened?
// because it was closed in a thread in close1_r()
if ( fd >= 0 && s_open[fd] ) { char *xx=NULL;*xx=0; }
// . now inc that count in case there was someone reading on
// that fd right before it was closed and we got it
// . ::close() call can now happen in a thread, so we
// need to inc this guy here now, too
// . so when that read returns it will know to re-do
// . this should really be named s_openCounts!!
if ( fd >= 0 ) s_closeCounts [ fd ]++;
// . we now record this
// . that way if our fd gets closed in closeLeastUsed() or
// in close1_r() due to a rename/unlink then we know it!
// . this fixes a race condition of closeCounts in Threads.cpp
// where we did not know that the fd had been stolen from
// us and assigned to another file because our close1_r()
// had called ::close() on our fd and our closeCount algo
// failed us. see the top of this file for more description
// into this bug fix.
m_closeCount = s_closeCounts[fd];
}
if ( t1 >= 0 ) {
int64_t dt = gettimeofdayInMilliseconds() - t1 ;
if ( dt > 1 ) log(LOG_INFO,
"disk: call to open(%s) blocked for "
"%"INT64" ms.",getFilename(),dt);
}
// copy errno to g_errno
if ( fd <= -1 ) {
g_errno = errno;
log("disk: error open(%s) : %s fd %i",
getFilename(),strerror(g_errno),(int)fd);
return -1;
}
if ( g_conf.m_logDebugDisk ) sanityCheck();
// we're another open file
s_numOpenFiles++;
// debug log
if ( g_conf.m_logDebugDisk )
log("disk: opened1 fd %i for %s #openfiles=%i this=0x%"PTRFMT,
(int)fd,getFilename(),(int)s_numOpenFiles,(PTRTYPE)this);
// set this file descriptor, the other stuff remains the same
//s_fds [ m_vfd ] = fd;
m_fd = fd;
// 0 means stdout, right? why am i seeing it get assigned???
if ( fd == 0 )
log("disk: Found fd of 0 when opening %s.",getFilename());
// reset
s_writing [ fd ] = 0;
s_unlinking [ fd ] = 0;
// update the time stamp
s_timestamps [ fd ] = gettimeofdayInMillisecondsLocal();
s_open [ fd ] = true;
s_filePtrs [ fd ] = this;
if ( g_conf.m_logDebugDisk ) sanityCheck();
// add file to linked list of active files
//addFileToLinkedList ( this );
return fd;
}
