Merge pull request #150 from derfian/disk-logging

Disk debug logging
This commit is contained in:
Henrik Andersson 2017-09-23 10:13:17 +02:00 committed by GitHub
commit 17fa29c783
3 changed files with 49 additions and 35 deletions

73
disk.c
View File

@ -221,28 +221,28 @@ ftruncate_growable(int fd, off_t length)
/* Get current position */ /* Get current position */
if ((pos = lseek(fd, 0, SEEK_CUR)) == -1) if ((pos = lseek(fd, 0, SEEK_CUR)) == -1)
{ {
logger(Core, Error, "ftruncate_growable(), lseek() failed: %s", strerror(errno)); logger(Disk, Error, "ftruncate_growable(), lseek() failed: %s", strerror(errno));
return -1; return -1;
} }
/* Seek to new size */ /* Seek to new size */
if (lseek(fd, length, SEEK_SET) == -1) if (lseek(fd, length, SEEK_SET) == -1)
{ {
logger(Core, Error, "ftruncate_growable(), lseek() failed: %s", strerror(errno)); logger(Disk, Error, "ftruncate_growable(), lseek() failed: %s", strerror(errno));
return -1; return -1;
} }
/* Write a zero */ /* Write a zero */
if (write(fd, &zero, 1) == -1) if (write(fd, &zero, 1) == -1)
{ {
logger(Core, Error, "ftruncate_growable(), write() failed: %s", strerror(errno)); logger(Disk, Error, "ftruncate_growable(), write() failed: %s", strerror(errno));
return -1; return -1;
} }
/* Truncate. This shouldn't fail. */ /* Truncate. This shouldn't fail. */
if (ftruncate(fd, length) == -1) if (ftruncate(fd, length) == -1)
{ {
logger(Core, Error, "ftruncate_growable(), ftruncate() failed: %s", logger(Disk, Error, "ftruncate_growable(), ftruncate() failed: %s",
strerror(errno)); strerror(errno));
return -1; return -1;
} }
@ -250,7 +250,7 @@ ftruncate_growable(int fd, off_t length)
/* Restore position */ /* Restore position */
if (lseek(fd, pos, SEEK_SET) == -1) if (lseek(fd, pos, SEEK_SET) == -1)
{ {
logger(Core, Error, "ftruncate_growable(), lseek() failed: %s", strerror(errno)); logger(Disk, Error, "ftruncate_growable(), lseek() failed: %s", strerror(errno));
return -1; return -1;
} }
@ -355,6 +355,9 @@ disk_create(uint32 device_id, uint32 accessmask, uint32 sharemode, uint32 create
char path[PATH_MAX]; char path[PATH_MAX];
struct stat filestat; struct stat filestat;
logger(Disk, Debug, "disk_create(device_id=0x%x, accessmask=0x%x, sharemode=0x%x, "
"create_disp=%d, flags=0x%x, fname=%s, ...)", device_id, accessmask,
sharemode, create_disposition, flags_and_attributes, filename);
handle = 0; handle = 0;
dirp = NULL; dirp = NULL;
flags = 0; flags = 0;
@ -443,7 +446,7 @@ disk_create(uint32 device_id, uint32 accessmask, uint32 sharemode, uint32 create
return RD_STATUS_NO_SUCH_FILE; return RD_STATUS_NO_SUCH_FILE;
default: default:
logger(Core, Error, "disk_create(), opendir() failed: %s", logger(Disk, Error, "disk_create(), opendir() failed: %s",
strerror(errno)); strerror(errno));
return RD_STATUS_NO_SUCH_FILE; return RD_STATUS_NO_SUCH_FILE;
} }
@ -487,7 +490,7 @@ disk_create(uint32 device_id, uint32 accessmask, uint32 sharemode, uint32 create
return RD_STATUS_OBJECT_NAME_COLLISION; return RD_STATUS_OBJECT_NAME_COLLISION;
default: default:
logger(Core, Error, "disk_create(), open() failed: %s", logger(Disk, Error, "disk_create(), open() failed: %s",
strerror(errno)); strerror(errno));
return RD_STATUS_NO_SUCH_FILE; return RD_STATUS_NO_SUCH_FILE;
} }
@ -495,13 +498,13 @@ disk_create(uint32 device_id, uint32 accessmask, uint32 sharemode, uint32 create
/* all read and writes of files should be non blocking */ /* all read and writes of files should be non blocking */
if (fcntl(handle, F_SETFL, O_NONBLOCK) == -1) if (fcntl(handle, F_SETFL, O_NONBLOCK) == -1)
logger(Core, Error, "disk_create(), fcntl() failed: %s", strerror(errno)); logger(Disk, Error, "disk_create(), fcntl() failed: %s", strerror(errno));
} }
if (handle >= MAX_OPEN_FILES) if (handle >= MAX_OPEN_FILES)
{ {
logger(Core, Error, logger(Disk, Error,
"disk_create(), maximum number of open files (%s) reached, increase MAX_OPEN_FILES!", "disk_create(), maximum number of open files (%s) reached, increase MAX_OPEN_FILES!",
handle); handle);
exit(EX_SOFTWARE); exit(EX_SOFTWARE);
@ -528,6 +531,7 @@ disk_create(uint32 device_id, uint32 accessmask, uint32 sharemode, uint32 create
static RD_NTSTATUS static RD_NTSTATUS
disk_close(RD_NTHANDLE handle) disk_close(RD_NTHANDLE handle)
{ {
logger(Disk, Debug, "disk_close(handle=0x%x)", handle);
struct fileinfo *pfinfo; struct fileinfo *pfinfo;
pfinfo = &(g_fileinfo[handle]); pfinfo = &(g_fileinfo[handle]);
@ -541,14 +545,14 @@ disk_close(RD_NTHANDLE handle)
{ {
if (closedir(pfinfo->pdir) < 0) if (closedir(pfinfo->pdir) < 0)
{ {
logger(Core, Error, "disk_close(), closedir() failed: %s", strerror(errno)); logger(Disk, Error, "disk_close(), closedir() failed: %s", strerror(errno));
return RD_STATUS_INVALID_HANDLE; return RD_STATUS_INVALID_HANDLE;
} }
if (pfinfo->delete_on_close) if (pfinfo->delete_on_close)
if (rmdir(pfinfo->path) < 0) if (rmdir(pfinfo->path) < 0)
{ {
logger(Core, Error, "disk_close(), rmdir() failed: %s", logger(Disk, Error, "disk_close(), rmdir() failed: %s",
strerror(errno)); strerror(errno));
return RD_STATUS_ACCESS_DENIED; return RD_STATUS_ACCESS_DENIED;
} }
@ -558,13 +562,13 @@ disk_close(RD_NTHANDLE handle)
{ {
if (close(handle) < 0) if (close(handle) < 0)
{ {
logger(Core, Error, "disk_close(), close() failed: %s", strerror(errno)); logger(Disk, Error, "disk_close(), close() failed: %s", strerror(errno));
return RD_STATUS_INVALID_HANDLE; return RD_STATUS_INVALID_HANDLE;
} }
if (pfinfo->delete_on_close) if (pfinfo->delete_on_close)
if (unlink(pfinfo->path) < 0) if (unlink(pfinfo->path) < 0)
{ {
logger(Core, Error, "disk_close(), unlink() failed: %s", logger(Disk, Error, "disk_close(), unlink() failed: %s",
strerror(errno)); strerror(errno));
return RD_STATUS_ACCESS_DENIED; return RD_STATUS_ACCESS_DENIED;
} }
@ -605,7 +609,7 @@ disk_read(RD_NTHANDLE handle, uint8 * data, uint32 length, uint32 offset, uint32
/* return STATUS_FILE_IS_A_DIRECTORY; */ /* return STATUS_FILE_IS_A_DIRECTORY; */
return RD_STATUS_NOT_IMPLEMENTED; return RD_STATUS_NOT_IMPLEMENTED;
default: default:
logger(Core, Error, "disk_read(), read failed: %s", logger(Disk, Error, "disk_read(), read failed: %s",
strerror(errno)); strerror(errno));
return RD_STATUS_INVALID_PARAMETER; return RD_STATUS_INVALID_PARAMETER;
} }
@ -627,7 +631,7 @@ disk_write(RD_NTHANDLE handle, uint8 * data, uint32 length, uint32 offset, uint3
if (n < 0) if (n < 0)
{ {
logger(Core, Error, "disk_write(), write() failed: %s", strerror(errno)); logger(Disk, Error, "disk_write(), write() failed: %s", strerror(errno));
*result = 0; *result = 0;
switch (errno) switch (errno)
{ {
@ -646,6 +650,7 @@ disk_write(RD_NTHANDLE handle, uint8 * data, uint32 length, uint32 offset, uint3
RD_NTSTATUS RD_NTSTATUS
disk_query_information(RD_NTHANDLE handle, uint32 info_class, STREAM out) disk_query_information(RD_NTHANDLE handle, uint32 info_class, STREAM out)
{ {
logger(Disk, Debug, "disk_query_information(handle=0x%x, info_class=0x%x)", handle, info_class);
uint32 file_attributes, ft_high, ft_low; uint32 file_attributes, ft_high, ft_low;
struct stat filestat; struct stat filestat;
char *path, *filename; char *path, *filename;
@ -655,7 +660,7 @@ disk_query_information(RD_NTHANDLE handle, uint32 info_class, STREAM out)
/* Get information about file */ /* Get information about file */
if (fstat(handle, &filestat) != 0) if (fstat(handle, &filestat) != 0)
{ {
logger(Core, Error, "disk_query_information(), stat() failed: %s", strerror(errno)); logger(Disk, Error, "disk_query_information(), stat() failed: %s", strerror(errno));
out_uint8(out, 0); out_uint8(out, 0);
return RD_STATUS_ACCESS_DENIED; return RD_STATUS_ACCESS_DENIED;
} }
@ -720,7 +725,7 @@ disk_query_information(RD_NTHANDLE handle, uint32 info_class, STREAM out)
break; break;
default: default:
logger(Protocol, Warning, logger(Disk, Warning,
"disk_query_information(), unhandled query information class 0x%x", "disk_query_information(), unhandled query information class 0x%x",
info_class); info_class);
return RD_STATUS_INVALID_PARAMETER; return RD_STATUS_INVALID_PARAMETER;
@ -731,6 +736,7 @@ disk_query_information(RD_NTHANDLE handle, uint32 info_class, STREAM out)
RD_NTSTATUS RD_NTSTATUS
disk_set_information(RD_NTHANDLE handle, uint32 info_class, STREAM in, STREAM out) disk_set_information(RD_NTHANDLE handle, uint32 info_class, STREAM in, STREAM out)
{ {
logger(Disk, Debug, "disk_set_information(handle=0x%x, info_class=0x%x, ...)", handle, info_class);
uint32 length, file_attributes, ft_high, ft_low; uint32 length, file_attributes, ft_high, ft_low;
char *newname, fullpath[PATH_MAX]; char *newname, fullpath[PATH_MAX];
struct fileinfo *pfinfo; struct fileinfo *pfinfo;
@ -796,7 +802,7 @@ disk_set_information(RD_NTHANDLE handle, uint32 info_class, STREAM in, STREAM ou
if (access_time || write_time || change_time) if (access_time || write_time || change_time)
{ {
logger(Protocol, Debug, logger(Disk, Debug,
"disk_set_information(), access time='%s', modify time='%s'", "disk_set_information(), access time='%s', modify time='%s'",
ctime(&tvs.actime), ctime(&tvs.modtime)); ctime(&tvs.actime), ctime(&tvs.modtime));
if (utime(pfinfo->path, &tvs) && errno != EPERM) if (utime(pfinfo->path, &tvs) && errno != EPERM)
@ -815,7 +821,7 @@ disk_set_information(RD_NTHANDLE handle, uint32 info_class, STREAM in, STREAM ou
mode &= 0777; mode &= 0777;
logger(Protocol, Debug, "disk_set_information(), access mode 0%o", mode); logger(Disk, Debug, "disk_set_information(), access mode 0%o", mode);
if (fchmod(handle, mode)) if (fchmod(handle, mode))
return RD_STATUS_ACCESS_DENIED; return RD_STATUS_ACCESS_DENIED;
@ -844,7 +850,7 @@ disk_set_information(RD_NTHANDLE handle, uint32 info_class, STREAM in, STREAM ou
if (rename(pfinfo->path, fullpath) != 0) if (rename(pfinfo->path, fullpath) != 0)
{ {
logger(Core, Error, "disk_set_information(), rename() failed: %s", logger(Disk, Error, "disk_set_information(), rename() failed: %s",
strerror(errno)); strerror(errno));
return RD_STATUS_ACCESS_DENIED; return RD_STATUS_ACCESS_DENIED;
} }
@ -927,7 +933,7 @@ disk_set_information(RD_NTHANDLE handle, uint32 info_class, STREAM in, STREAM ou
break; break;
default: default:
logger(Protocol, Warning, logger(Disk, Warning,
"disk_set_information(), unhandled information class 0x%x", "disk_set_information(), unhandled information class 0x%x",
info_class); info_class);
return RD_STATUS_INVALID_PARAMETER; return RD_STATUS_INVALID_PARAMETER;
@ -938,6 +944,7 @@ disk_set_information(RD_NTHANDLE handle, uint32 info_class, STREAM in, STREAM ou
RD_NTSTATUS RD_NTSTATUS
disk_check_notify(RD_NTHANDLE handle) disk_check_notify(RD_NTHANDLE handle)
{ {
logger(Disk, Debug, "disk_check_notify(handle=0x%x)", handle);
struct fileinfo *pfinfo; struct fileinfo *pfinfo;
RD_NTSTATUS status = RD_STATUS_PENDING; RD_NTSTATUS status = RD_STATUS_PENDING;
@ -969,7 +976,7 @@ disk_check_notify(RD_NTHANDLE handle)
RD_NTSTATUS RD_NTSTATUS
disk_create_notify(RD_NTHANDLE handle, uint32 info_class) disk_create_notify(RD_NTHANDLE handle, uint32 info_class)
{ {
logger(Disk, Debug, "disk_create_notify(handle=0x%x, info_class=0x%x)", handle, info_class);
struct fileinfo *pfinfo; struct fileinfo *pfinfo;
RD_NTSTATUS ret = RD_STATUS_PENDING; RD_NTSTATUS ret = RD_STATUS_PENDING;
@ -1005,7 +1012,7 @@ NotifyInfo(RD_NTHANDLE handle, uint32 info_class, NOTIFY * p)
pfinfo = &(g_fileinfo[handle]); pfinfo = &(g_fileinfo[handle]);
if (fstat(handle, &filestat) < 0) if (fstat(handle, &filestat) < 0)
{ {
logger(Core, Error, "NotifyInfo(), fstat failed: %s", strerror(errno)); logger(Disk, Error, "NotifyInfo(), fstat failed: %s", strerror(errno));
return RD_STATUS_ACCESS_DENIED; return RD_STATUS_ACCESS_DENIED;
} }
p->modify_time = filestat.st_mtime; p->modify_time = filestat.st_mtime;
@ -1017,7 +1024,7 @@ NotifyInfo(RD_NTHANDLE handle, uint32 info_class, NOTIFY * p)
dpr = opendir(pfinfo->path); dpr = opendir(pfinfo->path);
if (!dpr) if (!dpr)
{ {
logger(Core, Error, "NotifyInfo(), opendir failed: %s", strerror(errno)); logger(Disk, Error, "NotifyInfo(), opendir failed: %s", strerror(errno));
return RD_STATUS_ACCESS_DENIED; return RD_STATUS_ACCESS_DENIED;
} }
@ -1113,6 +1120,7 @@ FsVolumeInfo(char *fpath)
RD_NTSTATUS RD_NTSTATUS
disk_query_volume_information(RD_NTHANDLE handle, uint32 info_class, STREAM out) disk_query_volume_information(RD_NTHANDLE handle, uint32 info_class, STREAM out)
{ {
logger(Disk, Debug, "disk_query_volume_information(handle=0x%x, info_class=0x%x)", handle, info_class);
struct STATFS_T stat_fs; struct STATFS_T stat_fs;
struct fileinfo *pfinfo; struct fileinfo *pfinfo;
FsInfoType *fsinfo; FsInfoType *fsinfo;
@ -1121,7 +1129,7 @@ disk_query_volume_information(RD_NTHANDLE handle, uint32 info_class, STREAM out)
if (STATFS_FN(pfinfo->path, &stat_fs) != 0) if (STATFS_FN(pfinfo->path, &stat_fs) != 0)
{ {
logger(Core, Error, "disk_query_volume_information(), statfs() failed: %s", logger(Disk, Error, "disk_query_volume_information(), statfs() failed: %s",
strerror(errno)); strerror(errno));
return RD_STATUS_ACCESS_DENIED; return RD_STATUS_ACCESS_DENIED;
} }
@ -1180,7 +1188,7 @@ disk_query_volume_information(RD_NTHANDLE handle, uint32 info_class, STREAM out)
case FileFsMaximumInformation: case FileFsMaximumInformation:
default: default:
logger(Protocol, Warning, logger(Disk, Warning,
"disk_query_volume_information(), unhandled volume info class 0x%x", "disk_query_volume_information(), unhandled volume info class 0x%x",
info_class); info_class);
return RD_STATUS_INVALID_PARAMETER; return RD_STATUS_INVALID_PARAMETER;
@ -1191,6 +1199,8 @@ disk_query_volume_information(RD_NTHANDLE handle, uint32 info_class, STREAM out)
RD_NTSTATUS RD_NTSTATUS
disk_query_directory(RD_NTHANDLE handle, uint32 info_class, char *pattern, STREAM out) disk_query_directory(RD_NTHANDLE handle, uint32 info_class, char *pattern, STREAM out)
{ {
logger(Disk, Debug, "disk_query_directory(handle=0x%x, info_class=0x%x, pattern=%s, ...)",
handle, info_class, pattern);
uint32 file_attributes, ft_low, ft_high; uint32 file_attributes, ft_low, ft_high;
char *dirname, fullpath[PATH_MAX]; char *dirname, fullpath[PATH_MAX];
DIR *pdir; DIR *pdir;
@ -1242,7 +1252,7 @@ disk_query_directory(RD_NTHANDLE handle, uint32 info_class, char *pattern, STREA
default: default:
/* Fatal error. By returning STATUS_NO_SUCH_FILE, /* Fatal error. By returning STATUS_NO_SUCH_FILE,
the directory list operation will be aborted */ the directory list operation will be aborted */
logger(Core, Error, logger(Disk, Error,
"disk_query_directory(), stat() failed: %s", "disk_query_directory(), stat() failed: %s",
strerror(errno)); strerror(errno));
out_uint8(out, 0); out_uint8(out, 0);
@ -1265,7 +1275,7 @@ disk_query_directory(RD_NTHANDLE handle, uint32 info_class, char *pattern, STREA
break; break;
default: default:
logger(Protocol, Warning, logger(Disk, Warning,
"disk_query_directory(), unhandled directory info class 0x%x", "disk_query_directory(), unhandled directory info class 0x%x",
info_class); info_class);
return RD_STATUS_INVALID_PARAMETER; return RD_STATUS_INVALID_PARAMETER;
@ -1375,7 +1385,7 @@ disk_query_directory(RD_NTHANDLE handle, uint32 info_class, char *pattern, STREA
default: default:
logger(Protocol, Warning, logger(Disk, Warning,
"disk_query_directory(), unhandled directory info class 0x%x", "disk_query_directory(), unhandled directory info class 0x%x",
info_class); info_class);
return RD_STATUS_INVALID_PARAMETER; return RD_STATUS_INVALID_PARAMETER;
@ -1389,6 +1399,7 @@ disk_query_directory(RD_NTHANDLE handle, uint32 info_class, char *pattern, STREA
static RD_NTSTATUS static RD_NTSTATUS
disk_device_control(RD_NTHANDLE handle, uint32 request, STREAM in, STREAM out) disk_device_control(RD_NTHANDLE handle, uint32 request, STREAM in, STREAM out)
{ {
logger(Disk, Debug, "disk_device_control(handle=0x%x, request=0x%x, ...)", handle, request);
if (((request >> 16) != 20) || ((request >> 16) != 9)) if (((request >> 16) != 20) || ((request >> 16) != 9))
return RD_STATUS_INVALID_PARAMETER; return RD_STATUS_INVALID_PARAMETER;
@ -1396,14 +1407,12 @@ disk_device_control(RD_NTHANDLE handle, uint32 request, STREAM in, STREAM out)
request >>= 2; request >>= 2;
request &= 0xfff; request &= 0xfff;
printf("DISK IOCTL %d\n", request);
switch (request) switch (request)
{ {
case 25: /* ? */ case 25: /* ? */
case 42: /* ? */ case 42: /* ? */
default: default:
logger(Protocol, Warning, "disk_device_control(), unhandled disk ioctl %d", logger(Disk, Warning, "disk_device_control(), unhandled disk ioctl %d",
request); request);
return RD_STATUS_INVALID_PARAMETER; return RD_STATUS_INVALID_PARAMETER;
} }

View File

@ -241,7 +241,8 @@ static char *subject[] = {
"Protocol", "Protocol",
"Graphics", "Graphics",
"Core", "Core",
"SmartCard" "SmartCard",
"Disk"
}; };
static log_level_t _logger_level = Warning; static log_level_t _logger_level = Warning;
@ -256,7 +257,8 @@ static log_level_t _logger_level = Warning;
| (1 << Protocol) \ | (1 << Protocol) \
| (1 << Graphics) \ | (1 << Graphics) \
| (1 << Core) \ | (1 << Core) \
| (1 << SmartCard) | (1 << SmartCard) \
| (1 << Disk)
static int _logger_subjects = DEFAULT_LOGGER_SUBJECTS; static int _logger_subjects = DEFAULT_LOGGER_SUBJECTS;
@ -351,6 +353,8 @@ logger_set_subjects(char *subjects)
bit = (1 << Core); bit = (1 << Core);
else if (strcmp(token, "SmartCard") == 0) else if (strcmp(token, "SmartCard") == 0)
bit = (1 << SmartCard); bit = (1 << SmartCard);
else if (strcmp(token, "Disk") == 0)
bit = (1 << Disk);
else else
continue; continue;

View File

@ -44,7 +44,8 @@ typedef enum log_subject_t
Protocol, Protocol,
Graphics, Graphics,
Core, Core,
SmartCard SmartCard,
Disk
} log_subject_t; } log_subject_t;
void logger(log_subject_t c, log_level_t lvl, char *format, ...); void logger(log_subject_t c, log_level_t lvl, char *format, ...);