source3/modules/vfs_time_audit.c

   1 /*
   2  * Time auditing VFS module for samba.  Log time taken for VFS call to syslog
   3  * facility.
   4  *
   5  * Copyright (C) Abhidnya Chirmule <achirmul@in.ibm.com> 2009
   6  *
   7  * This program is free software; you can redistribute it and/or modify
   8  * it under the terms of the GNU General Public License as published by
   9  * the Free Software Foundation; either version 3 of the License, or
  10  * (at your option) any later version.
  11  *
  12  * This program is distributed in the hope that it will be useful,
  13  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  15  * GNU General Public License for more details.
  16  *
  17  * You should have received a copy of the GNU General Public License
  18  * along with this program; if not, see <http://www.gnu.org/licenses/>.
  19  */
  20
  21 /*
  22  * This module implements logging for time taken for all Samba VFS operations.
  23  *
  24  * vfs objects = time_audit
  25  */
  26
  27
  28 #include "includes.h"
  29 #include "smbd/smbd.h"
  30 #include "ntioctl.h"
  31 #include "lib/util/tevent_unix.h"
  32 #include "lib/util/tevent_ntstatus.h"
  33
  34 #undef DBGC_CLASS
  35 #define DBGC_CLASS DBGC_VFS
  36
  37 static double audit_timeout;
  38
  39 static void smb_time_audit_log_msg(const char *syscallname, double elapsed,
  40                                     const char *msg)
  41 {
  42         DEBUG(0, ("WARNING: VFS call \"%s\" took unexpectedly long "
  43                   "(%.2f seconds) %s%s-- Validate that file and storage "
  44                   "subsystems are operating normally\n", syscallname,
  45                   elapsed, (msg != NULL) ? msg : "",
  46                   (msg != NULL) ? " " : ""));
  47 }
  48
  49 static void smb_time_audit_log(const char *syscallname, double elapsed)
  50 {
  51         smb_time_audit_log_msg(syscallname, elapsed, NULL);
  52 }
  53
  54 static void smb_time_audit_log_fsp(const char *syscallname, double elapsed,
  55                                    const struct files_struct *fsp)
  56 {
  57         char *base_name = NULL;
  58         char *connectpath = NULL;
  59         char *msg = NULL;
  60
  61         if (fsp == NULL) {
  62                 smb_time_audit_log(syscallname, elapsed);
  63                 return;
  64         }
  65         if (fsp->conn)
  66                 connectpath = fsp->conn->connectpath;
  67         if (fsp->fsp_name)
  68                 base_name = fsp->fsp_name->base_name;
  69
  70         if (connectpath != NULL && base_name != NULL) {
  71                 msg = talloc_asprintf(talloc_tos(), "filename = \"%s/%s\"",
  72                                       connectpath, base_name);
  73         } else if (connectpath != NULL && base_name == NULL) {
  74                 msg = talloc_asprintf(talloc_tos(), "connectpath = \"%s\", "
  75                                       "base_name = <NULL>",
  76                                       connectpath);
  77         } else if (connectpath == NULL && base_name != NULL) {
  78                 msg = talloc_asprintf(talloc_tos(), "connectpath = <NULL>, "
  79                                       "base_name = \"%s\"",
  80                                       base_name);
  81         } else { /* connectpath == NULL && base_name == NULL */
  82                 msg = talloc_asprintf(talloc_tos(), "connectpath = <NULL>, "
  83                                       "base_name = <NULL>");
  84         }
  85         smb_time_audit_log_msg(syscallname, elapsed, msg);
  86         TALLOC_FREE(msg);
  87 }
  88
  89 static void smb_time_audit_log_fname(const char *syscallname, double elapsed,
  90                                     const char *fname)
  91 {
  92         char cwd[PATH_MAX];
  93         char *msg = NULL;
  94
  95         if (getcwd(cwd, sizeof(cwd)) == NULL) {
  96                 snprintf(cwd, sizeof(cwd), "<getcwd() error %d>", errno);
  97         }
  98         if (fname != NULL) {
  99                 msg = talloc_asprintf(talloc_tos(),
 100                                       "cwd = \"%s\", filename = \"%s\"",
 101                                       cwd, fname);
 102         } else {
 103                 msg = talloc_asprintf(talloc_tos(),
 104                                       "cwd = \"%s\", filename = <NULL>",
 105                                       cwd);
 106         }
 107         smb_time_audit_log_msg(syscallname, elapsed, msg);
 108         TALLOC_FREE(msg);
 109 }
 110
 111 static void smb_time_audit_log_smb_fname(const char *syscallname, double elapsed,
 112                                        const struct smb_filename *smb_fname)
 113 {
 114         if (smb_fname != NULL) {
 115                 smb_time_audit_log_fname(syscallname, elapsed,
 116                                          smb_fname->base_name);
 117         } else {
 118                 smb_time_audit_log_fname(syscallname, elapsed,
 119                                          "smb_fname = <NULL>");
 120         }
 121 }
 122
 123 static int smb_time_audit_connect(vfs_handle_struct *handle,
 124                                   const char *svc, const char *user)
 125 {
 126         int result;
 127         struct timespec ts1,ts2;
 128         double timediff;
 129
 130         if (!handle) {
 131                 return -1;
 132         }
 133
 134         clock_gettime_mono(&ts1);
 135         result = SMB_VFS_NEXT_CONNECT(handle, svc, user);
 136         clock_gettime_mono(&ts2);
 137         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 138         if (timediff > audit_timeout) {
 139                 smb_time_audit_log_msg("connect", timediff, user);
 140         }
 141         return result;
 142 }
 143
 144 static void smb_time_audit_disconnect(vfs_handle_struct *handle)
 145 {
 146         struct timespec ts1,ts2;
 147         double timediff;
 148
 149         clock_gettime_mono(&ts1);
 150         SMB_VFS_NEXT_DISCONNECT(handle);
 151         clock_gettime_mono(&ts2);
 152         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 153
 154         if (timediff > audit_timeout) {
 155                 smb_time_audit_log("disconnect", timediff);
 156         }
 157 }
 158
 159 static uint64_t smb_time_audit_disk_free(vfs_handle_struct *handle,
 160                                          const char *path,
 161                                          bool small_query, uint64_t *bsize,
 162                                          uint64_t *dfree, uint64_t *dsize)
 163 {
 164         uint64_t result;
 165         struct timespec ts1,ts2;
 166         double timediff;
 167
 168         clock_gettime_mono(&ts1);
 169         result = SMB_VFS_NEXT_DISK_FREE(handle, path, small_query, bsize,
 170                                         dfree, dsize);
 171         clock_gettime_mono(&ts2);
 172         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 173
 174         /* Don't have a reasonable notion of failure here */
 175         if (timediff > audit_timeout) {
 176                 smb_time_audit_log_fname("disk_free", timediff, path);
 177         }
 178
 179         return result;
 180 }
 181
 182 static int smb_time_audit_get_quota(struct vfs_handle_struct *handle,
 183                                     enum SMB_QUOTA_TYPE qtype, unid_t id,
 184                                     SMB_DISK_QUOTA *qt)
 185 {
 186         int result;
 187         struct timespec ts1,ts2;
 188         double timediff;
 189
 190         clock_gettime_mono(&ts1);
 191         result = SMB_VFS_NEXT_GET_QUOTA(handle, qtype, id, qt);
 192         clock_gettime_mono(&ts2);
 193         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 194
 195         if (timediff > audit_timeout) {
 196                 smb_time_audit_log("get_quota", timediff);
 197         }
 198         return result;
 199 }
 200
 201 static int smb_time_audit_set_quota(struct vfs_handle_struct *handle,
 202                                     enum SMB_QUOTA_TYPE qtype, unid_t id,
 203                                     SMB_DISK_QUOTA *qt)
 204 {
 205         int result;
 206         struct timespec ts1,ts2;
 207         double timediff;
 208
 209         clock_gettime_mono(&ts1);
 210         result = SMB_VFS_NEXT_SET_QUOTA(handle, qtype, id, qt);
 211         clock_gettime_mono(&ts2);
 212         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 213
 214         if (timediff > audit_timeout) {
 215                 smb_time_audit_log("set_quota", timediff);
 216         }
 217
 218         return result;
 219 }
 220
 221 static int smb_time_audit_get_shadow_copy_data(struct vfs_handle_struct *handle,
 222                                                struct files_struct *fsp,
 223                                                struct shadow_copy_data *shadow_copy_data,
 224                                                bool labels)
 225 {
 226         int result;
 227         struct timespec ts1,ts2;
 228         double timediff;
 229
 230         clock_gettime_mono(&ts1);
 231         result = SMB_VFS_NEXT_GET_SHADOW_COPY_DATA(handle, fsp,
 232                                                    shadow_copy_data, labels);
 233         clock_gettime_mono(&ts2);
 234         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 235
 236         if (timediff > audit_timeout) {
 237                 smb_time_audit_log_fsp("get_shadow_copy_data", timediff, fsp);
 238         }
 239
 240         return result;
 241 }
 242
 243 static int smb_time_audit_statvfs(struct vfs_handle_struct *handle,
 244                                   const char *path,
 245                                   struct vfs_statvfs_struct *statbuf)
 246 {
 247         int result;
 248         struct timespec ts1,ts2;
 249         double timediff;
 250
 251         clock_gettime_mono(&ts1);
 252         result = SMB_VFS_NEXT_STATVFS(handle, path, statbuf);
 253         clock_gettime_mono(&ts2);
 254         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 255
 256         if (timediff > audit_timeout) {
 257                 smb_time_audit_log_fname("statvfs", timediff, path);
 258         }
 259
 260         return result;
 261 }
 262
 263 static uint32_t smb_time_audit_fs_capabilities(struct vfs_handle_struct *handle,
 264                                                enum timestamp_set_resolution *p_ts_res)
 265 {
 266         uint32_t result;
 267         struct timespec ts1,ts2;
 268         double timediff;
 269
 270         clock_gettime_mono(&ts1);
 271         result = SMB_VFS_NEXT_FS_CAPABILITIES(handle, p_ts_res);
 272         clock_gettime_mono(&ts2);
 273         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 274
 275         if (timediff > audit_timeout) {
 276                 smb_time_audit_log("fs_capabilities", timediff);
 277         }
 278
 279         return result;
 280 }
 281
 282 static DIR *smb_time_audit_opendir(vfs_handle_struct *handle,
 283                                               const char *fname,
 284                                               const char *mask, uint32 attr)
 285 {
 286         DIR *result;
 287         struct timespec ts1,ts2;
 288         double timediff;
 289
 290         clock_gettime_mono(&ts1);
 291         result = SMB_VFS_NEXT_OPENDIR(handle, fname, mask, attr);
 292         clock_gettime_mono(&ts2);
 293         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 294
 295         if (timediff > audit_timeout) {
 296                 smb_time_audit_log_fname("opendir", timediff, fname);
 297         }
 298
 299         return result;
 300 }
 301
 302 static DIR *smb_time_audit_fdopendir(vfs_handle_struct *handle,
 303                                               files_struct *fsp,
 304                                               const char *mask, uint32 attr)
 305 {
 306         DIR *result;
 307         struct timespec ts1,ts2;
 308         double timediff;
 309
 310         clock_gettime_mono(&ts1);
 311         result = SMB_VFS_NEXT_FDOPENDIR(handle, fsp, mask, attr);
 312         clock_gettime_mono(&ts2);
 313         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 314
 315         if (timediff > audit_timeout) {
 316                 smb_time_audit_log_fsp("fdopendir", timediff, fsp);
 317         }
 318
 319         return result;
 320 }
 321
 322 static struct dirent *smb_time_audit_readdir(vfs_handle_struct *handle,
 323                                                  DIR *dirp,
 324                                                  SMB_STRUCT_STAT *sbuf)
 325 {
 326         struct dirent *result;
 327         struct timespec ts1,ts2;
 328         double timediff;
 329
 330         clock_gettime_mono(&ts1);
 331         result = SMB_VFS_NEXT_READDIR(handle, dirp, sbuf);
 332         clock_gettime_mono(&ts2);
 333         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 334
 335         if (timediff > audit_timeout) {
 336                 smb_time_audit_log("readdir", timediff);
 337         }
 338
 339         return result;
 340 }
 341
 342 static void smb_time_audit_seekdir(vfs_handle_struct *handle,
 343                                    DIR *dirp, long offset)
 344 {
 345         struct timespec ts1,ts2;
 346         double timediff;
 347
 348         clock_gettime_mono(&ts1);
 349         SMB_VFS_NEXT_SEEKDIR(handle, dirp, offset);
 350         clock_gettime_mono(&ts2);
 351         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 352
 353         if (timediff > audit_timeout) {
 354                 smb_time_audit_log("seekdir", timediff);
 355         }
 356
 357 }
 358
 359 static long smb_time_audit_telldir(vfs_handle_struct *handle,
 360                                    DIR *dirp)
 361 {
 362         long result;
 363         struct timespec ts1,ts2;
 364         double timediff;
 365
 366         clock_gettime_mono(&ts1);
 367         result = SMB_VFS_NEXT_TELLDIR(handle, dirp);
 368         clock_gettime_mono(&ts2);
 369         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 370
 371         if (timediff > audit_timeout) {
 372                 smb_time_audit_log("telldir", timediff);
 373         }
 374
 375         return result;
 376 }
 377
 378 static void smb_time_audit_rewinddir(vfs_handle_struct *handle,
 379                                      DIR *dirp)
 380 {
 381         struct timespec ts1,ts2;
 382         double timediff;
 383
 384         clock_gettime_mono(&ts1);
 385         SMB_VFS_NEXT_REWINDDIR(handle, dirp);
 386         clock_gettime_mono(&ts2);
 387         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 388
 389         if (timediff > audit_timeout) {
 390                 smb_time_audit_log("rewinddir", timediff);
 391         }
 392
 393 }
 394
 395 static int smb_time_audit_mkdir(vfs_handle_struct *handle,
 396                                 const char *path, mode_t mode)
 397 {
 398         int result;
 399         struct timespec ts1,ts2;
 400         double timediff;
 401
 402         clock_gettime_mono(&ts1);
 403         result = SMB_VFS_NEXT_MKDIR(handle, path, mode);
 404         clock_gettime_mono(&ts2);
 405         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 406
 407         if (timediff > audit_timeout) {
 408                 smb_time_audit_log_fname("mkdir", timediff, path);
 409         }
 410
 411         return result;
 412 }
 413
 414 static int smb_time_audit_rmdir(vfs_handle_struct *handle,
 415                                 const char *path)
 416 {
 417         int result;
 418         struct timespec ts1,ts2;
 419         double timediff;
 420
 421         clock_gettime_mono(&ts1);
 422         result = SMB_VFS_NEXT_RMDIR(handle, path);
 423         clock_gettime_mono(&ts2);
 424         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 425
 426         if (timediff > audit_timeout) {
 427                 smb_time_audit_log_fname("rmdir", timediff, path);
 428         }
 429
 430         return result;
 431 }
 432
 433 static int smb_time_audit_closedir(vfs_handle_struct *handle,
 434                                    DIR *dirp)
 435 {
 436         int result;
 437         struct timespec ts1,ts2;
 438         double timediff;
 439
 440         clock_gettime_mono(&ts1);
 441         result = SMB_VFS_NEXT_CLOSEDIR(handle, dirp);
 442         clock_gettime_mono(&ts2);
 443         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 444
 445         if (timediff > audit_timeout) {
 446                 smb_time_audit_log("closedir", timediff);
 447         }
 448
 449         return result;
 450 }
 451
 452 static void smb_time_audit_init_search_op(vfs_handle_struct *handle,
 453                                           DIR *dirp)
 454 {
 455         struct timespec ts1,ts2;
 456         double timediff;
 457
 458         clock_gettime_mono(&ts1);
 459         SMB_VFS_NEXT_INIT_SEARCH_OP(handle, dirp);
 460         clock_gettime_mono(&ts2);
 461         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 462
 463         if (timediff > audit_timeout) {
 464                 smb_time_audit_log("init_search_op", timediff);
 465         }
 466 }
 467
 468 static int smb_time_audit_open(vfs_handle_struct *handle,
 469                                struct smb_filename *fname,
 470                                files_struct *fsp,
 471                                int flags, mode_t mode)
 472 {
 473         int result;
 474         struct timespec ts1,ts2;
 475         double timediff;
 476
 477         clock_gettime_mono(&ts1);
 478         result = SMB_VFS_NEXT_OPEN(handle, fname, fsp, flags, mode);
 479         clock_gettime_mono(&ts2);
 480         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 481
 482         if (timediff > audit_timeout) {
 483                 smb_time_audit_log_fsp("open", timediff, fsp);
 484         }
 485
 486         return result;
 487 }
 488
 489 static NTSTATUS smb_time_audit_create_file(vfs_handle_struct *handle,
 490                                            struct smb_request *req,
 491                                            uint16_t root_dir_fid,
 492                                            struct smb_filename *fname,
 493                                            uint32_t access_mask,
 494                                            uint32_t share_access,
 495                                            uint32_t create_disposition,
 496                                            uint32_t create_options,
 497                                            uint32_t file_attributes,
 498                                            uint32_t oplock_request,
 499                                            struct smb2_lease *lease,
 500                                            uint64_t allocation_size,
 501                                            uint32_t private_flags,
 502                                            struct security_descriptor *sd,
 503                                            struct ea_list *ea_list,
 504                                            files_struct **result_fsp,
 505                                            int *pinfo)
 506 {
 507         NTSTATUS result;
 508         struct timespec ts1,ts2;
 509         double timediff;
 510
 511         clock_gettime_mono(&ts1);
 512         result = SMB_VFS_NEXT_CREATE_FILE(
 513                 handle,                                 /* handle */
 514                 req,                                    /* req */
 515                 root_dir_fid,                           /* root_dir_fid */
 516                 fname,                                  /* fname */
 517                 access_mask,                            /* access_mask */
 518                 share_access,                           /* share_access */
 519                 create_disposition,                     /* create_disposition*/
 520                 create_options,                         /* create_options */
 521                 file_attributes,                        /* file_attributes */
 522                 oplock_request,                         /* oplock_request */
 523                 lease,                                  /* lease */
 524                 allocation_size,                        /* allocation_size */
 525                 private_flags,
 526                 sd,                                     /* sd */
 527                 ea_list,                                /* ea_list */
 528                 result_fsp,                             /* result */
 529                 pinfo);
 530         clock_gettime_mono(&ts2);
 531         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 532
 533         if (timediff > audit_timeout) {
 534                 /*
 535                  * can't use result_fsp this time, may have
 536                  * invalid content causing smbd crash
 537                  */
 538                 smb_time_audit_log_smb_fname("create_file", timediff,
 539                                            fname);
 540         }
 541
 542         return result;
 543 }
 544
 545 static int smb_time_audit_close(vfs_handle_struct *handle, files_struct *fsp)
 546 {
 547         int result;
 548         struct timespec ts1,ts2;
 549         double timediff;
 550
 551         clock_gettime_mono(&ts1);
 552         result = SMB_VFS_NEXT_CLOSE(handle, fsp);
 553         clock_gettime_mono(&ts2);
 554         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 555
 556         if (timediff > audit_timeout) {
 557                 smb_time_audit_log_fsp("close", timediff, fsp);
 558         }
 559
 560         return result;
 561 }
 562
 563 static ssize_t smb_time_audit_read(vfs_handle_struct *handle,
 564                                    files_struct *fsp, void *data, size_t n)
 565 {
 566         ssize_t result;
 567         struct timespec ts1,ts2;
 568         double timediff;
 569
 570         clock_gettime_mono(&ts1);
 571         result = SMB_VFS_NEXT_READ(handle, fsp, data, n);
 572         clock_gettime_mono(&ts2);
 573         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 574
 575         if (timediff > audit_timeout) {
 576                 smb_time_audit_log_fsp("read", timediff, fsp);
 577         }
 578
 579         return result;
 580 }
 581
 582 static ssize_t smb_time_audit_pread(vfs_handle_struct *handle,
 583                                     files_struct *fsp,
 584                                     void *data, size_t n, off_t offset)
 585 {
 586         ssize_t result;
 587         struct timespec ts1,ts2;
 588         double timediff;
 589
 590         clock_gettime_mono(&ts1);
 591         result = SMB_VFS_NEXT_PREAD(handle, fsp, data, n, offset);
 592         clock_gettime_mono(&ts2);
 593         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 594
 595         if (timediff > audit_timeout) {
 596                 smb_time_audit_log_fsp("pread", timediff, fsp);
 597         }
 598
 599         return result;
 600 }
 601
 602 struct smb_time_audit_pread_state {
 603         struct files_struct *fsp;
 604         struct timespec ts1;
 605         ssize_t ret;
 606         int err;
 607 };
 608
 609 static void smb_time_audit_pread_done(struct tevent_req *subreq);
 610
 611 static struct tevent_req *smb_time_audit_pread_send(
 612         struct vfs_handle_struct *handle, TALLOC_CTX *mem_ctx,
 613         struct tevent_context *ev, struct files_struct *fsp,
 614         void *data, size_t n, off_t offset)
 615 {
 616         struct tevent_req *req, *subreq;
 617         struct smb_time_audit_pread_state *state;
 618
 619         req = tevent_req_create(mem_ctx, &state,
 620                                 struct smb_time_audit_pread_state);
 621         if (req == NULL) {
 622                 return NULL;
 623         }
 624         clock_gettime_mono(&state->ts1);
 625         state->fsp = fsp;
 626
 627         subreq = SMB_VFS_NEXT_PREAD_SEND(state, ev, handle, fsp, data,
 628                                          n, offset);
 629         if (tevent_req_nomem(subreq, req)) {
 630                 return tevent_req_post(req, ev);
 631         }
 632         tevent_req_set_callback(subreq, smb_time_audit_pread_done, req);
 633         return req;
 634 }
 635
 636 static void smb_time_audit_pread_done(struct tevent_req *subreq)
 637 {
 638         struct tevent_req *req = tevent_req_callback_data(
 639                 subreq, struct tevent_req);
 640         struct smb_time_audit_pread_state *state = tevent_req_data(
 641                 req, struct smb_time_audit_pread_state);
 642
 643         state->ret = SMB_VFS_PREAD_RECV(subreq, &state->err);
 644         TALLOC_FREE(subreq);
 645         tevent_req_done(req);
 646 }
 647
 648 static ssize_t smb_time_audit_pread_recv(struct tevent_req *req, int *err)
 649 {
 650         struct smb_time_audit_pread_state *state = tevent_req_data(
 651                 req, struct smb_time_audit_pread_state);
 652         struct timespec ts2;
 653         double timediff;
 654
 655         clock_gettime_mono(&ts2);
 656         timediff = nsec_time_diff(&ts2,&state->ts1)*1.0e-9;
 657
 658         if (timediff > audit_timeout) {
 659                 smb_time_audit_log_fsp("pread", timediff, state->fsp);
 660         }
 661
 662         if (tevent_req_is_unix_error(req, err)) {
 663                 return -1;
 664         }
 665         *err = state->err;
 666         return state->ret;
 667 }
 668
 669 static ssize_t smb_time_audit_write(vfs_handle_struct *handle,
 670                                     files_struct *fsp,
 671                                     const void *data, size_t n)
 672 {
 673         ssize_t result;
 674         struct timespec ts1,ts2;
 675         double timediff;
 676
 677         clock_gettime_mono(&ts1);
 678         result = SMB_VFS_NEXT_WRITE(handle, fsp, data, n);
 679         clock_gettime_mono(&ts2);
 680         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 681
 682         if (timediff > audit_timeout) {
 683                 smb_time_audit_log_fsp("write", timediff, fsp);
 684         }
 685
 686         return result;
 687 }
 688
 689 static ssize_t smb_time_audit_pwrite(vfs_handle_struct *handle,
 690                                      files_struct *fsp,
 691                                      const void *data, size_t n,
 692                                      off_t offset)
 693 {
 694         ssize_t result;
 695         struct timespec ts1,ts2;
 696         double timediff;
 697
 698         clock_gettime_mono(&ts1);
 699         result = SMB_VFS_NEXT_PWRITE(handle, fsp, data, n, offset);
 700         clock_gettime_mono(&ts2);
 701         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 702
 703         if (timediff > audit_timeout) {
 704                 smb_time_audit_log_fsp("pwrite", timediff, fsp);
 705         }
 706
 707         return result;
 708 }
 709
 710 struct smb_time_audit_pwrite_state {
 711         struct files_struct *fsp;
 712         struct timespec ts1;
 713         ssize_t ret;
 714         int err;
 715 };
 716
 717 static void smb_time_audit_pwrite_done(struct tevent_req *subreq);
 718
 719 static struct tevent_req *smb_time_audit_pwrite_send(
 720         struct vfs_handle_struct *handle, TALLOC_CTX *mem_ctx,
 721         struct tevent_context *ev, struct files_struct *fsp,
 722         const void *data, size_t n, off_t offset)
 723 {
 724         struct tevent_req *req, *subreq;
 725         struct smb_time_audit_pwrite_state *state;
 726
 727         req = tevent_req_create(mem_ctx, &state,
 728                                 struct smb_time_audit_pwrite_state);
 729         if (req == NULL) {
 730                 return NULL;
 731         }
 732         clock_gettime_mono(&state->ts1);
 733         state->fsp = fsp;
 734
 735         subreq = SMB_VFS_NEXT_PWRITE_SEND(state, ev, handle, fsp, data,
 736                                          n, offset);
 737         if (tevent_req_nomem(subreq, req)) {
 738                 return tevent_req_post(req, ev);
 739         }
 740         tevent_req_set_callback(subreq, smb_time_audit_pwrite_done, req);
 741         return req;
 742 }
 743
 744 static void smb_time_audit_pwrite_done(struct tevent_req *subreq)
 745 {
 746         struct tevent_req *req = tevent_req_callback_data(
 747                 subreq, struct tevent_req);
 748         struct smb_time_audit_pwrite_state *state = tevent_req_data(
 749                 req, struct smb_time_audit_pwrite_state);
 750
 751         state->ret = SMB_VFS_PWRITE_RECV(subreq, &state->err);
 752         TALLOC_FREE(subreq);
 753         tevent_req_done(req);
 754 }
 755
 756 static ssize_t smb_time_audit_pwrite_recv(struct tevent_req *req, int *err)
 757 {
 758         struct smb_time_audit_pwrite_state *state = tevent_req_data(
 759                 req, struct smb_time_audit_pwrite_state);
 760         struct timespec ts2;
 761         double timediff;
 762
 763         clock_gettime_mono(&ts2);
 764         timediff = nsec_time_diff(&ts2,&state->ts1)*1.0e-9;
 765
 766         if (timediff > audit_timeout) {
 767                 smb_time_audit_log_fsp("pwrite", timediff, state->fsp);
 768         }
 769
 770         if (tevent_req_is_unix_error(req, err)) {
 771                 return -1;
 772         }
 773         *err = state->err;
 774         return state->ret;
 775 }
 776
 777 static off_t smb_time_audit_lseek(vfs_handle_struct *handle,
 778                                       files_struct *fsp,
 779                                       off_t offset, int whence)
 780 {
 781         off_t result;
 782         struct timespec ts1,ts2;
 783         double timediff;
 784
 785         clock_gettime_mono(&ts1);
 786         result = SMB_VFS_NEXT_LSEEK(handle, fsp, offset, whence);
 787         clock_gettime_mono(&ts2);
 788         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 789
 790         if (timediff > audit_timeout) {
 791                 smb_time_audit_log_fsp("lseek", timediff, fsp);
 792         }
 793
 794         return result;
 795 }
 796
 797 static ssize_t smb_time_audit_sendfile(vfs_handle_struct *handle, int tofd,
 798                                        files_struct *fromfsp,
 799                                        const DATA_BLOB *hdr, off_t offset,
 800                                        size_t n)
 801 {
 802         ssize_t result;
 803         struct timespec ts1,ts2;
 804         double timediff;
 805
 806         clock_gettime_mono(&ts1);
 807         result = SMB_VFS_NEXT_SENDFILE(handle, tofd, fromfsp, hdr, offset, n);
 808         clock_gettime_mono(&ts2);
 809         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 810
 811         if (timediff > audit_timeout) {
 812                 smb_time_audit_log_fsp("sendfile", timediff, fromfsp);
 813         }
 814
 815         return result;
 816 }
 817
 818 static ssize_t smb_time_audit_recvfile(vfs_handle_struct *handle, int fromfd,
 819                                        files_struct *tofsp,
 820                                        off_t offset,
 821                                        size_t n)
 822 {
 823         ssize_t result;
 824         struct timespec ts1,ts2;
 825         double timediff;
 826
 827         clock_gettime_mono(&ts1);
 828         result = SMB_VFS_NEXT_RECVFILE(handle, fromfd, tofsp, offset, n);
 829         clock_gettime_mono(&ts2);
 830         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 831
 832         if (timediff > audit_timeout) {
 833                 smb_time_audit_log_fsp("recvfile", timediff, tofsp);
 834         }
 835
 836         return result;
 837 }
 838
 839 static int smb_time_audit_rename(vfs_handle_struct *handle,
 840                                  const struct smb_filename *oldname,
 841                                  const struct smb_filename *newname)
 842 {
 843         int result;
 844         struct timespec ts1,ts2;
 845         double timediff;
 846
 847         clock_gettime_mono(&ts1);
 848         result = SMB_VFS_NEXT_RENAME(handle, oldname, newname);
 849         clock_gettime_mono(&ts2);
 850         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 851
 852         if (timediff > audit_timeout) {
 853                 smb_time_audit_log_smb_fname("rename", timediff, newname);
 854         }
 855
 856         return result;
 857 }
 858
 859 static int smb_time_audit_fsync(vfs_handle_struct *handle, files_struct *fsp)
 860 {
 861         int result;
 862         struct timespec ts1,ts2;
 863         double timediff;
 864
 865         clock_gettime_mono(&ts1);
 866         result = SMB_VFS_NEXT_FSYNC(handle, fsp);
 867         clock_gettime_mono(&ts2);
 868         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 869
 870         if (timediff > audit_timeout) {
 871                 smb_time_audit_log_fsp("fsync", timediff, fsp);
 872         }
 873
 874         return result;
 875 }
 876
 877 struct smb_time_audit_fsync_state {
 878         struct files_struct *fsp;
 879         struct timespec ts1;
 880         int ret;
 881         int err;
 882 };
 883
 884 static void smb_time_audit_fsync_done(struct tevent_req *subreq);
 885
 886 static struct tevent_req *smb_time_audit_fsync_send(
 887         struct vfs_handle_struct *handle, TALLOC_CTX *mem_ctx,
 888         struct tevent_context *ev, struct files_struct *fsp)
 889 {
 890         struct tevent_req *req, *subreq;
 891         struct smb_time_audit_fsync_state *state;
 892
 893         req = tevent_req_create(mem_ctx, &state,
 894                                 struct smb_time_audit_fsync_state);
 895         if (req == NULL) {
 896                 return NULL;
 897         }
 898         clock_gettime_mono(&state->ts1);
 899         state->fsp = fsp;
 900
 901         subreq = SMB_VFS_NEXT_FSYNC_SEND(state, ev, handle, fsp);
 902         if (tevent_req_nomem(subreq, req)) {
 903                 return tevent_req_post(req, ev);
 904         }
 905         tevent_req_set_callback(subreq, smb_time_audit_fsync_done, req);
 906         return req;
 907 }
 908
 909 static void smb_time_audit_fsync_done(struct tevent_req *subreq)
 910 {
 911         struct tevent_req *req = tevent_req_callback_data(
 912                 subreq, struct tevent_req);
 913         struct smb_time_audit_fsync_state *state = tevent_req_data(
 914                 req, struct smb_time_audit_fsync_state);
 915
 916         state->ret = SMB_VFS_FSYNC_RECV(subreq, &state->err);
 917         TALLOC_FREE(subreq);
 918         tevent_req_done(req);
 919 }
 920
 921 static int smb_time_audit_fsync_recv(struct tevent_req *req, int *err)
 922 {
 923         struct smb_time_audit_fsync_state *state = tevent_req_data(
 924                 req, struct smb_time_audit_fsync_state);
 925         struct timespec ts2;
 926         double timediff;
 927
 928         clock_gettime_mono(&ts2);
 929         timediff = nsec_time_diff(&ts2,&state->ts1)*1.0e-9;
 930
 931         if (timediff > audit_timeout) {
 932                 smb_time_audit_log_fsp("fsync", timediff, state->fsp);
 933         }
 934
 935         if (tevent_req_is_unix_error(req, err)) {
 936                 return -1;
 937         }
 938         *err = state->err;
 939         return state->ret;
 940 }
 941
 942 static int smb_time_audit_stat(vfs_handle_struct *handle,
 943                                struct smb_filename *fname)
 944 {
 945         int result;
 946         struct timespec ts1,ts2;
 947         double timediff;
 948
 949         clock_gettime_mono(&ts1);
 950         result = SMB_VFS_NEXT_STAT(handle, fname);
 951         clock_gettime_mono(&ts2);
 952         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 953
 954         if (timediff > audit_timeout) {
 955                 smb_time_audit_log_smb_fname("stat", timediff, fname);
 956         }
 957
 958         return result;
 959 }
 960
 961 static int smb_time_audit_fstat(vfs_handle_struct *handle, files_struct *fsp,
 962                                 SMB_STRUCT_STAT *sbuf)
 963 {
 964         int result;
 965         struct timespec ts1,ts2;
 966         double timediff;
 967
 968         clock_gettime_mono(&ts1);
 969         result = SMB_VFS_NEXT_FSTAT(handle, fsp, sbuf);
 970         clock_gettime_mono(&ts2);
 971         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 972
 973         if (timediff > audit_timeout) {
 974                 smb_time_audit_log_fsp("fstat", timediff, fsp);
 975         }
 976
 977         return result;
 978 }
 979
 980 static int smb_time_audit_lstat(vfs_handle_struct *handle,
 981                                 struct smb_filename *path)
 982 {
 983         int result;
 984         struct timespec ts1,ts2;
 985         double timediff;
 986
 987         clock_gettime_mono(&ts1);
 988         result = SMB_VFS_NEXT_LSTAT(handle, path);
 989         clock_gettime_mono(&ts2);
 990         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
 991
 992         if (timediff > audit_timeout) {
 993                 smb_time_audit_log_smb_fname("lstat", timediff, path);
 994         }
 995
 996         return result;
 997 }
 998
 999 static uint64_t smb_time_audit_get_alloc_size(vfs_handle_struct *handle,
1000                                               files_struct *fsp,
1001                                               const SMB_STRUCT_STAT *sbuf)
1002 {
1003         uint64_t result;
1004         struct timespec ts1,ts2;
1005         double timediff;
1006
1007         clock_gettime_mono(&ts1);
1008         result = SMB_VFS_NEXT_GET_ALLOC_SIZE(handle, fsp, sbuf);
1009         clock_gettime_mono(&ts2);
1010         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1011
1012         if (timediff > audit_timeout) {
1013                 smb_time_audit_log_fsp("get_alloc_size", timediff, fsp);
1014         }
1015
1016         return result;
1017 }
1018
1019 static int smb_time_audit_unlink(vfs_handle_struct *handle,
1020                                  const struct smb_filename *path)
1021 {
1022         int result;
1023         struct timespec ts1,ts2;
1024         double timediff;
1025
1026         clock_gettime_mono(&ts1);
1027         result = SMB_VFS_NEXT_UNLINK(handle, path);
1028         clock_gettime_mono(&ts2);
1029         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1030
1031         if (timediff > audit_timeout) {
1032                 smb_time_audit_log_smb_fname("unlink", timediff, path);
1033         }
1034
1035         return result;
1036 }
1037
1038 static int smb_time_audit_chmod(vfs_handle_struct *handle,
1039                                 const char *path, mode_t mode)
1040 {
1041         int result;
1042         struct timespec ts1,ts2;
1043         double timediff;
1044
1045         clock_gettime_mono(&ts1);
1046         result = SMB_VFS_NEXT_CHMOD(handle, path, mode);
1047         clock_gettime_mono(&ts2);
1048         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1049
1050         if (timediff > audit_timeout) {
1051                 smb_time_audit_log_fname("chmod", timediff, path);
1052         }
1053
1054         return result;
1055 }
1056
1057 static int smb_time_audit_fchmod(vfs_handle_struct *handle, files_struct *fsp,
1058                                  mode_t mode)
1059 {
1060         int result;
1061         struct timespec ts1,ts2;
1062         double timediff;
1063
1064         clock_gettime_mono(&ts1);
1065         result = SMB_VFS_NEXT_FCHMOD(handle, fsp, mode);
1066         clock_gettime_mono(&ts2);
1067         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1068
1069         if (timediff > audit_timeout) {
1070                 smb_time_audit_log_fsp("fchmod", timediff, fsp);
1071         }
1072
1073         return result;
1074 }
1075
1076 static int smb_time_audit_chown(vfs_handle_struct *handle,
1077                                 const char *path, uid_t uid, gid_t gid)
1078 {
1079         int result;
1080         struct timespec ts1,ts2;
1081         double timediff;
1082
1083         clock_gettime_mono(&ts1);
1084         result = SMB_VFS_NEXT_CHOWN(handle, path, uid, gid);
1085         clock_gettime_mono(&ts2);
1086         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1087
1088         if (timediff > audit_timeout) {
1089                 smb_time_audit_log_fname("chown", timediff, path);
1090         }
1091
1092         return result;
1093 }
1094
1095 static int smb_time_audit_fchown(vfs_handle_struct *handle, files_struct *fsp,
1096                                  uid_t uid, gid_t gid)
1097 {
1098         int result;
1099         struct timespec ts1,ts2;
1100         double timediff;
1101
1102         clock_gettime_mono(&ts1);
1103         result = SMB_VFS_NEXT_FCHOWN(handle, fsp, uid, gid);
1104         clock_gettime_mono(&ts2);
1105         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1106
1107         if (timediff > audit_timeout) {
1108                 smb_time_audit_log_fsp("fchown", timediff, fsp);
1109         }
1110
1111         return result;
1112 }
1113
1114 static int smb_time_audit_lchown(vfs_handle_struct *handle,
1115                                  const char *path, uid_t uid, gid_t gid)
1116 {
1117         int result;
1118         struct timespec ts1,ts2;
1119         double timediff;
1120
1121         clock_gettime_mono(&ts1);
1122         result = SMB_VFS_NEXT_LCHOWN(handle, path, uid, gid);
1123         clock_gettime_mono(&ts2);
1124         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1125
1126         if (timediff > audit_timeout) {
1127                 smb_time_audit_log_fname("lchown", timediff, path);
1128         }
1129
1130         return result;
1131 }
1132
1133 static int smb_time_audit_chdir(vfs_handle_struct *handle, const char *path)
1134 {
1135         int result;
1136         struct timespec ts1,ts2;
1137         double timediff;
1138
1139         clock_gettime_mono(&ts1);
1140         result = SMB_VFS_NEXT_CHDIR(handle, path);
1141         clock_gettime_mono(&ts2);
1142         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1143
1144         if (timediff > audit_timeout) {
1145                 smb_time_audit_log_fname("chdir", timediff, path);
1146         }
1147
1148         return result;
1149 }
1150
1151 static char *smb_time_audit_getwd(vfs_handle_struct *handle)
1152 {
1153         char *result;
1154         struct timespec ts1,ts2;
1155         double timediff;
1156
1157         clock_gettime_mono(&ts1);
1158         result = SMB_VFS_NEXT_GETWD(handle);
1159         clock_gettime_mono(&ts2);
1160         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1161
1162         if (timediff > audit_timeout) {
1163                 smb_time_audit_log("getwd", timediff);
1164         }
1165
1166         return result;
1167 }
1168
1169 static int smb_time_audit_ntimes(vfs_handle_struct *handle,
1170                                  const struct smb_filename *path,
1171                                  struct smb_file_time *ft)
1172 {
1173         int result;
1174         struct timespec ts1,ts2;
1175         double timediff;
1176
1177         clock_gettime_mono(&ts1);
1178         result = SMB_VFS_NEXT_NTIMES(handle, path, ft);
1179         clock_gettime_mono(&ts2);
1180         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1181
1182         if (timediff > audit_timeout) {
1183                 smb_time_audit_log_smb_fname("ntimes", timediff, path);
1184         }
1185
1186         return result;
1187 }
1188
1189 static int smb_time_audit_ftruncate(vfs_handle_struct *handle,
1190                                     files_struct *fsp,
1191                                     off_t len)
1192 {
1193         int result;
1194         struct timespec ts1,ts2;
1195         double timediff;
1196
1197         clock_gettime_mono(&ts1);
1198         result = SMB_VFS_NEXT_FTRUNCATE(handle, fsp, len);
1199         clock_gettime_mono(&ts2);
1200         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1201
1202         if (timediff > audit_timeout) {
1203                 smb_time_audit_log_fsp("ftruncate", timediff, fsp);
1204         }
1205
1206         return result;
1207 }
1208
1209 static int smb_time_audit_fallocate(vfs_handle_struct *handle,
1210                                     files_struct *fsp,
1211                                     enum vfs_fallocate_mode mode,
1212                                     off_t offset,
1213                                     off_t len)
1214 {
1215         int result;
1216         struct timespec ts1,ts2;
1217         double timediff;
1218
1219         clock_gettime_mono(&ts1);
1220         result = SMB_VFS_NEXT_FALLOCATE(handle, fsp, mode, offset, len);
1221         clock_gettime_mono(&ts2);
1222         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1223
1224         if (timediff > audit_timeout) {
1225                 smb_time_audit_log_fsp("fallocate", timediff, fsp);
1226         }
1227
1228         return result;
1229 }
1230
1231 static bool smb_time_audit_lock(vfs_handle_struct *handle, files_struct *fsp,
1232                                 int op, off_t offset, off_t count,
1233                                 int type)
1234 {
1235         bool result;
1236         struct timespec ts1,ts2;
1237         double timediff;
1238
1239         clock_gettime_mono(&ts1);
1240         result = SMB_VFS_NEXT_LOCK(handle, fsp, op, offset, count, type);
1241         clock_gettime_mono(&ts2);
1242         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1243
1244         if (timediff > audit_timeout) {
1245                 smb_time_audit_log_fsp("lock", timediff, fsp);
1246         }
1247
1248         return result;
1249 }
1250
1251 static int smb_time_audit_kernel_flock(struct vfs_handle_struct *handle,
1252                                        struct files_struct *fsp,
1253                                        uint32 share_mode, uint32 access_mask)
1254 {
1255         int result;
1256         struct timespec ts1,ts2;
1257         double timediff;
1258
1259         clock_gettime_mono(&ts1);
1260         result = SMB_VFS_NEXT_KERNEL_FLOCK(handle, fsp, share_mode,
1261                                            access_mask);
1262         clock_gettime_mono(&ts2);
1263         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1264
1265         if (timediff > audit_timeout) {
1266                 smb_time_audit_log_fsp("kernel_flock", timediff, fsp);
1267         }
1268
1269         return result;
1270 }
1271
1272 static int smb_time_audit_linux_setlease(vfs_handle_struct *handle,
1273                                          files_struct *fsp,
1274                                          int leasetype)
1275 {
1276         int result;
1277         struct timespec ts1,ts2;
1278         double timediff;
1279
1280         clock_gettime_mono(&ts1);
1281         result = SMB_VFS_NEXT_LINUX_SETLEASE(handle, fsp, leasetype);
1282         clock_gettime_mono(&ts2);
1283         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1284
1285         if (timediff > audit_timeout) {
1286                 smb_time_audit_log_fsp("linux_setlease", timediff, fsp);
1287         }
1288
1289         return result;
1290 }
1291
1292 static bool smb_time_audit_getlock(vfs_handle_struct *handle,
1293                                    files_struct *fsp,
1294                                    off_t *poffset, off_t *pcount,
1295                                    int *ptype, pid_t *ppid)
1296 {
1297         bool result;
1298         struct timespec ts1,ts2;
1299         double timediff;
1300
1301         clock_gettime_mono(&ts1);
1302         result = SMB_VFS_NEXT_GETLOCK(handle, fsp, poffset, pcount, ptype,
1303                                       ppid);
1304         clock_gettime_mono(&ts2);
1305         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1306
1307         if (timediff > audit_timeout) {
1308                 smb_time_audit_log_fsp("getlock", timediff, fsp);
1309         }
1310
1311         return result;
1312 }
1313
1314 static int smb_time_audit_symlink(vfs_handle_struct *handle,
1315                                   const char *oldpath, const char *newpath)
1316 {
1317         int result;
1318         struct timespec ts1,ts2;
1319         double timediff;
1320
1321         clock_gettime_mono(&ts1);
1322         result = SMB_VFS_NEXT_SYMLINK(handle, oldpath, newpath);
1323         clock_gettime_mono(&ts2);
1324         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1325
1326         if (timediff > audit_timeout) {
1327                 smb_time_audit_log_fname("symlink", timediff, newpath);
1328         }
1329
1330         return result;
1331 }
1332
1333 static int smb_time_audit_readlink(vfs_handle_struct *handle,
1334                           const char *path, char *buf, size_t bufsiz)
1335 {
1336         int result;
1337         struct timespec ts1,ts2;
1338         double timediff;
1339
1340         clock_gettime_mono(&ts1);
1341         result = SMB_VFS_NEXT_READLINK(handle, path, buf, bufsiz);
1342         clock_gettime_mono(&ts2);
1343         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1344
1345         if (timediff > audit_timeout) {
1346                 smb_time_audit_log_fname("readlink", timediff, path);
1347         }
1348
1349         return result;
1350 }
1351
1352 static int smb_time_audit_link(vfs_handle_struct *handle,
1353                                const char *oldpath, const char *newpath)
1354 {
1355         int result;
1356         struct timespec ts1,ts2;
1357         double timediff;
1358
1359         clock_gettime_mono(&ts1);
1360         result = SMB_VFS_NEXT_LINK(handle, oldpath, newpath);
1361         clock_gettime_mono(&ts2);
1362         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1363
1364         if (timediff > audit_timeout) {
1365                 smb_time_audit_log_fname("link", timediff, newpath);
1366         }
1367
1368         return result;
1369 }
1370
1371 static int smb_time_audit_mknod(vfs_handle_struct *handle,
1372                                 const char *pathname, mode_t mode,
1373                                 SMB_DEV_T dev)
1374 {
1375         int result;
1376         struct timespec ts1,ts2;
1377         double timediff;
1378
1379         clock_gettime_mono(&ts1);
1380         result = SMB_VFS_NEXT_MKNOD(handle, pathname, mode, dev);
1381         clock_gettime_mono(&ts2);
1382         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1383
1384         if (timediff > audit_timeout) {
1385                 smb_time_audit_log_fname("mknod", timediff, pathname);
1386         }
1387
1388         return result;
1389 }
1390
1391 static char *smb_time_audit_realpath(vfs_handle_struct *handle,
1392                                      const char *path)
1393 {
1394         char *result;
1395         struct timespec ts1,ts2;
1396         double timediff;
1397
1398         clock_gettime_mono(&ts1);
1399         result = SMB_VFS_NEXT_REALPATH(handle, path);
1400         clock_gettime_mono(&ts2);
1401         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1402
1403         if (timediff > audit_timeout) {
1404                 smb_time_audit_log_fname("realpath", timediff, path);
1405         }
1406
1407         return result;
1408 }
1409
1410 static NTSTATUS smb_time_audit_notify_watch(struct vfs_handle_struct *handle,
1411                         struct sys_notify_context *ctx,
1412                         const char *path,
1413                         uint32_t *filter,
1414                         uint32_t *subdir_filter,
1415                         void (*callback)(struct sys_notify_context *ctx,
1416                                         void *private_data,
1417                                         struct notify_event *ev),
1418                         void *private_data, void *handle_p)
1419 {
1420         NTSTATUS result;
1421         struct timespec ts1,ts2;
1422         double timediff;
1423
1424         clock_gettime_mono(&ts1);
1425         result = SMB_VFS_NEXT_NOTIFY_WATCH(handle, ctx, path,
1426                                            filter, subdir_filter, callback,
1427                                            private_data, handle_p);
1428         clock_gettime_mono(&ts2);
1429         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1430
1431         if (timediff > audit_timeout) {
1432                 smb_time_audit_log_fname("notify_watch", timediff, path);
1433         }
1434
1435         return result;
1436 }
1437
1438 static int smb_time_audit_chflags(vfs_handle_struct *handle,
1439                                   const char *path, unsigned int flags)
1440 {
1441         int result;
1442         struct timespec ts1,ts2;
1443         double timediff;
1444
1445         clock_gettime_mono(&ts1);
1446         result = SMB_VFS_NEXT_CHFLAGS(handle, path, flags);
1447         clock_gettime_mono(&ts2);
1448         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1449
1450         if (timediff > audit_timeout) {
1451                 smb_time_audit_log_fname("chflags", timediff, path);
1452         }
1453
1454         return result;
1455 }
1456
1457 static struct file_id smb_time_audit_file_id_create(struct vfs_handle_struct *handle,
1458                                                     const SMB_STRUCT_STAT *sbuf)
1459 {
1460         struct file_id id_zero;
1461         struct file_id result;
1462         struct timespec ts1,ts2;
1463         double timediff;
1464
1465         ZERO_STRUCT(id_zero);
1466
1467         clock_gettime_mono(&ts1);
1468         result = SMB_VFS_NEXT_FILE_ID_CREATE(handle, sbuf);
1469         clock_gettime_mono(&ts2);
1470         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1471
1472         if (timediff > audit_timeout) {
1473                 smb_time_audit_log("file_id_create", timediff);
1474         }
1475
1476         return result;
1477 }
1478
1479 static NTSTATUS smb_time_audit_streaminfo(vfs_handle_struct *handle,
1480                                           struct files_struct *fsp,
1481                                           const char *fname,
1482                                           TALLOC_CTX *mem_ctx,
1483                                           unsigned int *pnum_streams,
1484                                           struct stream_struct **pstreams)
1485 {
1486         NTSTATUS result;
1487         struct timespec ts1,ts2;
1488         double timediff;
1489
1490         clock_gettime_mono(&ts1);
1491         result = SMB_VFS_NEXT_STREAMINFO(handle, fsp, fname, mem_ctx,
1492                                          pnum_streams, pstreams);
1493         clock_gettime_mono(&ts2);
1494         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1495
1496         if (timediff > audit_timeout) {
1497                 smb_time_audit_log_fsp("streaminfo", timediff, fsp);
1498         }
1499
1500         return result;
1501 }
1502
1503 static int smb_time_audit_get_real_filename(struct vfs_handle_struct *handle,
1504                                             const char *path,
1505                                             const char *name,
1506                                             TALLOC_CTX *mem_ctx,
1507                                             char **found_name)
1508 {
1509         int result;
1510         struct timespec ts1,ts2;
1511         double timediff;
1512
1513         clock_gettime_mono(&ts1);
1514         result = SMB_VFS_NEXT_GET_REAL_FILENAME(handle, path, name, mem_ctx,
1515                                                 found_name);
1516         clock_gettime_mono(&ts2);
1517         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1518
1519         if (timediff > audit_timeout) {
1520                 smb_time_audit_log_fname("get_real_filename", timediff, path);
1521         }
1522
1523         return result;
1524 }
1525
1526 static const char *smb_time_audit_connectpath(vfs_handle_struct *handle,
1527                                               const char *fname)
1528 {
1529         const char *result;
1530         struct timespec ts1,ts2;
1531         double timediff;
1532
1533         clock_gettime_mono(&ts1);
1534         result = SMB_VFS_NEXT_CONNECTPATH(handle, fname);
1535         clock_gettime_mono(&ts2);
1536         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1537
1538         if (timediff > audit_timeout) {
1539                 smb_time_audit_log_fname("connectpath", timediff, fname);
1540         }
1541
1542         return result;
1543 }
1544
1545 static NTSTATUS smb_time_audit_brl_lock_windows(struct vfs_handle_struct *handle,
1546                                                 struct byte_range_lock *br_lck,
1547                                                 struct lock_struct *plock,
1548                                                 bool blocking_lock)
1549 {
1550         NTSTATUS result;
1551         struct timespec ts1,ts2;
1552         double timediff;
1553
1554         clock_gettime_mono(&ts1);
1555         result = SMB_VFS_NEXT_BRL_LOCK_WINDOWS(handle, br_lck, plock,
1556                                                blocking_lock);
1557         clock_gettime_mono(&ts2);
1558         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1559
1560         if (timediff > audit_timeout) {
1561                 smb_time_audit_log_fsp("brl_lock_windows", timediff,
1562                                        brl_fsp(br_lck));
1563         }
1564
1565         return result;
1566 }
1567
1568 static bool smb_time_audit_brl_unlock_windows(struct vfs_handle_struct *handle,
1569                                               struct messaging_context *msg_ctx,
1570                                               struct byte_range_lock *br_lck,
1571                                               const struct lock_struct *plock)
1572 {
1573         bool result;
1574         struct timespec ts1,ts2;
1575         double timediff;
1576
1577         clock_gettime_mono(&ts1);
1578         result = SMB_VFS_NEXT_BRL_UNLOCK_WINDOWS(handle, msg_ctx, br_lck,
1579                                                  plock);
1580         clock_gettime_mono(&ts2);
1581         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1582
1583         if (timediff > audit_timeout) {
1584                 smb_time_audit_log_fsp("brl_unlock_windows", timediff,
1585                                        brl_fsp(br_lck));
1586         }
1587
1588         return result;
1589 }
1590
1591 static bool smb_time_audit_brl_cancel_windows(struct vfs_handle_struct *handle,
1592                                               struct byte_range_lock *br_lck,
1593                                               struct lock_struct *plock)
1594 {
1595         bool result;
1596         struct timespec ts1,ts2;
1597         double timediff;
1598
1599         clock_gettime_mono(&ts1);
1600         result = SMB_VFS_NEXT_BRL_CANCEL_WINDOWS(handle, br_lck, plock);
1601         clock_gettime_mono(&ts2);
1602         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1603
1604         if (timediff > audit_timeout) {
1605                 smb_time_audit_log_fsp("brl_cancel_windows", timediff,
1606                                        brl_fsp(br_lck));
1607         }
1608
1609         return result;
1610 }
1611
1612 static bool smb_time_audit_strict_lock(struct vfs_handle_struct *handle,
1613                                        struct files_struct *fsp,
1614                                        struct lock_struct *plock)
1615 {
1616         bool result;
1617         struct timespec ts1,ts2;
1618         double timediff;
1619
1620         clock_gettime_mono(&ts1);
1621         result = SMB_VFS_NEXT_STRICT_LOCK(handle, fsp, plock);
1622         clock_gettime_mono(&ts2);
1623         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1624
1625         if (timediff > audit_timeout) {
1626                 smb_time_audit_log_fsp("strict_lock", timediff, fsp);
1627         }
1628
1629         return result;
1630 }
1631
1632 static void smb_time_audit_strict_unlock(struct vfs_handle_struct *handle,
1633                                          struct files_struct *fsp,
1634                                          struct lock_struct *plock)
1635 {
1636         struct timespec ts1,ts2;
1637         double timediff;
1638
1639         clock_gettime_mono(&ts1);
1640         SMB_VFS_NEXT_STRICT_UNLOCK(handle, fsp, plock);
1641         clock_gettime_mono(&ts2);
1642         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1643
1644         if (timediff > audit_timeout) {
1645                 smb_time_audit_log_fsp("strict_unlock", timediff, fsp);
1646         }
1647 }
1648
1649 static NTSTATUS smb_time_audit_translate_name(struct vfs_handle_struct *handle,
1650                                               const char *name,
1651                                               enum vfs_translate_direction direction,
1652                                               TALLOC_CTX *mem_ctx,
1653                                               char **mapped_name)
1654 {
1655         NTSTATUS result;
1656         struct timespec ts1,ts2;
1657         double timediff;
1658
1659         clock_gettime_mono(&ts1);
1660         result = SMB_VFS_NEXT_TRANSLATE_NAME(handle, name, direction, mem_ctx,
1661                                              mapped_name);
1662         clock_gettime_mono(&ts2);
1663         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1664
1665         if (timediff > audit_timeout) {
1666                 smb_time_audit_log_fname("translate_name", timediff, name);
1667         }
1668
1669         return result;
1670 }
1671
1672 struct time_audit_cc_state {
1673         struct timespec ts_send;
1674         struct vfs_handle_struct *handle;
1675         off_t copied;
1676 };
1677 static void smb_time_audit_copy_chunk_done(struct tevent_req *subreq);
1678
1679 static struct tevent_req *smb_time_audit_copy_chunk_send(struct vfs_handle_struct *handle,
1680                                                          TALLOC_CTX *mem_ctx,
1681                                                          struct tevent_context *ev,
1682                                                          struct files_struct *src_fsp,
1683                                                          off_t src_off,
1684                                                          struct files_struct *dest_fsp,
1685                                                          off_t dest_off,
1686                                                          off_t num)
1687 {
1688         struct tevent_req *req;
1689         struct tevent_req *subreq;
1690         struct time_audit_cc_state *cc_state;
1691
1692         req = tevent_req_create(mem_ctx, &cc_state, struct time_audit_cc_state);
1693         if (req == NULL) {
1694                 return NULL;
1695         }
1696
1697         cc_state->handle = handle;
1698         clock_gettime_mono(&cc_state->ts_send);
1699         subreq = SMB_VFS_NEXT_COPY_CHUNK_SEND(handle, cc_state, ev,
1700                                               src_fsp, src_off,
1701                                               dest_fsp, dest_off, num);
1702         if (tevent_req_nomem(subreq, req)) {
1703                 return tevent_req_post(req, ev);
1704         }
1705
1706         tevent_req_set_callback(subreq, smb_time_audit_copy_chunk_done, req);
1707         return req;
1708 }
1709
1710 static void smb_time_audit_copy_chunk_done(struct tevent_req *subreq)
1711 {
1712         struct tevent_req *req = tevent_req_callback_data(
1713                 subreq, struct tevent_req);
1714         struct time_audit_cc_state *cc_state
1715                         = tevent_req_data(req, struct time_audit_cc_state);
1716         NTSTATUS status;
1717
1718         status = SMB_VFS_NEXT_COPY_CHUNK_RECV(cc_state->handle,
1719                                               subreq,
1720                                               &cc_state->copied);
1721         TALLOC_FREE(subreq);
1722         if (tevent_req_nterror(req, status)) {
1723                 return;
1724         }
1725         tevent_req_done(req);
1726 }
1727
1728 static NTSTATUS smb_time_audit_copy_chunk_recv(struct vfs_handle_struct *handle,
1729                                                struct tevent_req *req,
1730                                                off_t *copied)
1731 {
1732         struct time_audit_cc_state *cc_state
1733                         = tevent_req_data(req, struct time_audit_cc_state);
1734         struct timespec ts_recv;
1735         double timediff;
1736         NTSTATUS status;
1737
1738         clock_gettime_mono(&ts_recv);
1739         timediff = nsec_time_diff(&ts_recv, &cc_state->ts_send)*1.0e-9;
1740         if (timediff > audit_timeout) {
1741                 smb_time_audit_log("copy_chunk", timediff);
1742         }
1743
1744         *copied = cc_state->copied;
1745         if (tevent_req_is_nterror(req, &status)) {
1746                 tevent_req_received(req);
1747                 return status;
1748         }
1749
1750         tevent_req_received(req);
1751         return NT_STATUS_OK;
1752 }
1753
1754 static NTSTATUS smb_time_audit_get_compression(vfs_handle_struct *handle,
1755                                                TALLOC_CTX *mem_ctx,
1756                                                struct files_struct *fsp,
1757                                                struct smb_filename *smb_fname,
1758                                                uint16_t *_compression_fmt)
1759 {
1760         NTSTATUS result;
1761         struct timespec ts1,ts2;
1762         double timediff;
1763
1764         clock_gettime_mono(&ts1);
1765         result = SMB_VFS_NEXT_GET_COMPRESSION(handle, mem_ctx, fsp, smb_fname,
1766                                               _compression_fmt);
1767         clock_gettime_mono(&ts2);
1768         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1769
1770         if (timediff > audit_timeout) {
1771                 if (fsp !=  NULL) {
1772                         smb_time_audit_log_fsp("get_compression",
1773                                                timediff, fsp);
1774                 } else {
1775                         smb_time_audit_log_smb_fname("get_compression",
1776                                                      timediff, smb_fname);
1777                 }
1778         }
1779
1780         return result;
1781 }
1782
1783 static NTSTATUS smb_time_audit_set_compression(vfs_handle_struct *handle,
1784                                                TALLOC_CTX *mem_ctx,
1785                                                struct files_struct *fsp,
1786                                                uint16_t compression_fmt)
1787 {
1788         NTSTATUS result;
1789         struct timespec ts1,ts2;
1790         double timediff;
1791
1792         clock_gettime_mono(&ts1);
1793         result = SMB_VFS_NEXT_SET_COMPRESSION(handle, mem_ctx, fsp,
1794                                               compression_fmt);
1795         clock_gettime_mono(&ts2);
1796         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1797
1798         if (timediff > audit_timeout) {
1799                 smb_time_audit_log_fsp("set_compression", timediff, fsp);
1800         }
1801
1802         return result;
1803 }
1804
1805 static NTSTATUS smb_time_audit_readdir_attr(struct vfs_handle_struct *handle,
1806                                             const struct smb_filename *fname,
1807                                             TALLOC_CTX *mem_ctx,
1808                                             struct readdir_attr_data **pattr_data)
1809 {
1810         NTSTATUS status;
1811         struct timespec ts1,ts2;
1812         double timediff;
1813
1814         clock_gettime_mono(&ts1);
1815         status = SMB_VFS_NEXT_READDIR_ATTR(handle, fname, mem_ctx, pattr_data);
1816         clock_gettime_mono(&ts2);
1817         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1818
1819         if (timediff > audit_timeout) {
1820                 smb_time_audit_log_smb_fname("readdir_attr", timediff, fname);
1821         }
1822
1823         return status;
1824 }
1825
1826 static NTSTATUS smb_time_audit_fget_nt_acl(vfs_handle_struct *handle,
1827                                            files_struct *fsp,
1828                                            uint32 security_info,
1829                                            TALLOC_CTX *mem_ctx,
1830                                            struct security_descriptor **ppdesc)
1831 {
1832         NTSTATUS result;
1833         struct timespec ts1,ts2;
1834         double timediff;
1835
1836         clock_gettime_mono(&ts1);
1837         result = SMB_VFS_NEXT_FGET_NT_ACL(handle, fsp, security_info,
1838                                           mem_ctx, ppdesc);
1839         clock_gettime_mono(&ts2);
1840         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1841
1842         if (timediff > audit_timeout) {
1843                 smb_time_audit_log_fsp("fget_nt_acl", timediff, fsp);
1844         }
1845
1846         return result;
1847 }
1848
1849 static NTSTATUS smb_time_audit_get_nt_acl(vfs_handle_struct *handle,
1850                                           const char *name,
1851                                           uint32 security_info,
1852                                           TALLOC_CTX *mem_ctx,
1853                                           struct security_descriptor **ppdesc)
1854 {
1855         NTSTATUS result;
1856         struct timespec ts1,ts2;
1857         double timediff;
1858
1859         clock_gettime_mono(&ts1);
1860         result = SMB_VFS_NEXT_GET_NT_ACL(handle, name, security_info,
1861                                          mem_ctx, ppdesc);
1862         clock_gettime_mono(&ts2);
1863         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1864
1865         if (timediff > audit_timeout) {
1866                 smb_time_audit_log_fname("get_nt_acl", timediff, name);
1867         }
1868
1869         return result;
1870 }
1871
1872 static NTSTATUS smb_time_audit_fset_nt_acl(vfs_handle_struct *handle,
1873                                            files_struct *fsp,
1874                                            uint32 security_info_sent,
1875                                            const struct security_descriptor *psd)
1876 {
1877         NTSTATUS result;
1878         struct timespec ts1,ts2;
1879         double timediff;
1880
1881         clock_gettime_mono(&ts1);
1882         result = SMB_VFS_NEXT_FSET_NT_ACL(handle, fsp, security_info_sent,
1883                                           psd);
1884         clock_gettime_mono(&ts2);
1885         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1886
1887         if (timediff > audit_timeout) {
1888                 smb_time_audit_log_fsp("fset_nt_acl", timediff, fsp);
1889         }
1890
1891         return result;
1892 }
1893
1894 static int smb_time_audit_chmod_acl(vfs_handle_struct *handle,
1895                                     const char *path, mode_t mode)
1896 {
1897         int result;
1898         struct timespec ts1,ts2;
1899         double timediff;
1900
1901         clock_gettime_mono(&ts1);
1902         result = SMB_VFS_NEXT_CHMOD_ACL(handle, path, mode);
1903         clock_gettime_mono(&ts2);
1904         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1905
1906         if (timediff > audit_timeout) {
1907                 smb_time_audit_log_fname("chmod_acl", timediff, path);
1908         }
1909
1910         return result;
1911 }
1912
1913 static int smb_time_audit_fchmod_acl(vfs_handle_struct *handle,
1914                                      files_struct *fsp, mode_t mode)
1915 {
1916         int result;
1917         struct timespec ts1,ts2;
1918         double timediff;
1919
1920         clock_gettime_mono(&ts1);
1921         result = SMB_VFS_NEXT_FCHMOD_ACL(handle, fsp, mode);
1922         clock_gettime_mono(&ts2);
1923         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1924
1925         if (timediff > audit_timeout) {
1926                 smb_time_audit_log_fsp("fchmod_acl", timediff, fsp);
1927         }
1928
1929         return result;
1930 }
1931
1932 static SMB_ACL_T smb_time_audit_sys_acl_get_file(vfs_handle_struct *handle,
1933                                                  const char *path_p,
1934                                                  SMB_ACL_TYPE_T type,
1935                                                  TALLOC_CTX *mem_ctx)
1936 {
1937         SMB_ACL_T result;
1938         struct timespec ts1,ts2;
1939         double timediff;
1940
1941         clock_gettime_mono(&ts1);
1942         result = SMB_VFS_NEXT_SYS_ACL_GET_FILE(handle, path_p, type, mem_ctx);
1943         clock_gettime_mono(&ts2);
1944         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1945
1946         if (timediff > audit_timeout) {
1947                 smb_time_audit_log_fname("sys_acl_get_file", timediff, path_p);
1948         }
1949
1950         return result;
1951 }
1952
1953 static SMB_ACL_T smb_time_audit_sys_acl_get_fd(vfs_handle_struct *handle,
1954                                                files_struct *fsp,
1955                                                TALLOC_CTX *mem_ctx)
1956 {
1957         SMB_ACL_T result;
1958         struct timespec ts1,ts2;
1959         double timediff;
1960
1961         clock_gettime_mono(&ts1);
1962         result = SMB_VFS_NEXT_SYS_ACL_GET_FD(handle, fsp, mem_ctx);
1963         clock_gettime_mono(&ts2);
1964         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1965
1966         if (timediff > audit_timeout) {
1967                 smb_time_audit_log_fsp("sys_acl_get_fd", timediff, fsp);
1968         }
1969
1970         return result;
1971 }
1972
1973
1974 static int smb_time_audit_sys_acl_blob_get_file(vfs_handle_struct *handle,
1975                                                 const char *path_p,
1976                                                 TALLOC_CTX *mem_ctx,
1977                                                 char **blob_description,
1978                                                 DATA_BLOB *blob)
1979 {
1980         int result;
1981         struct timespec ts1,ts2;
1982         double timediff;
1983
1984         clock_gettime_mono(&ts1);
1985         result = SMB_VFS_NEXT_SYS_ACL_BLOB_GET_FILE(handle, path_p, mem_ctx, blob_description, blob);
1986         clock_gettime_mono(&ts2);
1987         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
1988
1989         if (timediff > audit_timeout) {
1990                 smb_time_audit_log("sys_acl_blob_get_file", timediff);
1991         }
1992
1993         return result;
1994 }
1995
1996 static int smb_time_audit_sys_acl_blob_get_fd(vfs_handle_struct *handle,
1997                                               files_struct *fsp,
1998                                               TALLOC_CTX *mem_ctx,
1999                                               char **blob_description,
2000                                               DATA_BLOB *blob)
2001 {
2002         int result;
2003         struct timespec ts1,ts2;
2004         double timediff;
2005
2006         clock_gettime_mono(&ts1);
2007         result = SMB_VFS_NEXT_SYS_ACL_BLOB_GET_FD(handle, fsp, mem_ctx, blob_description, blob);
2008         clock_gettime_mono(&ts2);
2009         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2010
2011         if (timediff > audit_timeout) {
2012                 smb_time_audit_log("sys_acl_blob_get_fd", timediff);
2013         }
2014
2015         return result;
2016 }
2017
2018 static int smb_time_audit_sys_acl_set_file(vfs_handle_struct *handle,
2019                                            const char *name,
2020                                            SMB_ACL_TYPE_T acltype,
2021                                            SMB_ACL_T theacl)
2022 {
2023         int result;
2024         struct timespec ts1,ts2;
2025         double timediff;
2026
2027         clock_gettime_mono(&ts1);
2028         result = SMB_VFS_NEXT_SYS_ACL_SET_FILE(handle, name, acltype,
2029                                                theacl);
2030         clock_gettime_mono(&ts2);
2031         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2032
2033         if (timediff > audit_timeout) {
2034                 smb_time_audit_log_fname("sys_acl_set_file", timediff, name);
2035         }
2036
2037         return result;
2038 }
2039
2040 static int smb_time_audit_sys_acl_set_fd(vfs_handle_struct *handle,
2041                                          files_struct *fsp,
2042                                          SMB_ACL_T theacl)
2043 {
2044         int result;
2045         struct timespec ts1,ts2;
2046         double timediff;
2047
2048         clock_gettime_mono(&ts1);
2049         result = SMB_VFS_NEXT_SYS_ACL_SET_FD(handle, fsp, theacl);
2050         clock_gettime_mono(&ts2);
2051         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2052
2053         if (timediff > audit_timeout) {
2054                 smb_time_audit_log_fsp("sys_acl_set_fd", timediff, fsp);
2055         }
2056
2057         return result;
2058 }
2059
2060 static int smb_time_audit_sys_acl_delete_def_file(vfs_handle_struct *handle,
2061                                                   const char *path)
2062 {
2063         int result;
2064         struct timespec ts1,ts2;
2065         double timediff;
2066
2067         clock_gettime_mono(&ts1);
2068         result = SMB_VFS_NEXT_SYS_ACL_DELETE_DEF_FILE(handle, path);
2069         clock_gettime_mono(&ts2);
2070         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2071
2072         if (timediff > audit_timeout) {
2073                 smb_time_audit_log_fname("sys_acl_delete_def_file", timediff, path);
2074         }
2075
2076         return result;
2077 }
2078
2079 static ssize_t smb_time_audit_getxattr(struct vfs_handle_struct *handle,
2080                                        const char *path, const char *name,
2081                                        void *value, size_t size)
2082 {
2083         ssize_t result;
2084         struct timespec ts1,ts2;
2085         double timediff;
2086
2087         clock_gettime_mono(&ts1);
2088         result = SMB_VFS_NEXT_GETXATTR(handle, path, name, value, size);
2089         clock_gettime_mono(&ts2);
2090         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2091
2092         if (timediff > audit_timeout) {
2093                 smb_time_audit_log_fname("getxattr", timediff, path);
2094         }
2095
2096         return result;
2097 }
2098
2099 static ssize_t smb_time_audit_fgetxattr(struct vfs_handle_struct *handle,
2100                                         struct files_struct *fsp,
2101                                         const char *name, void *value,
2102                                         size_t size)
2103 {
2104         ssize_t result;
2105         struct timespec ts1,ts2;
2106         double timediff;
2107
2108         clock_gettime_mono(&ts1);
2109         result = SMB_VFS_NEXT_FGETXATTR(handle, fsp, name, value, size);
2110         clock_gettime_mono(&ts2);
2111         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2112
2113         if (timediff > audit_timeout) {
2114                 smb_time_audit_log_fsp("fgetxattr", timediff, fsp);
2115         }
2116
2117         return result;
2118 }
2119
2120 static ssize_t smb_time_audit_listxattr(struct vfs_handle_struct *handle,
2121                                         const char *path, char *list,
2122                                         size_t size)
2123 {
2124         ssize_t result;
2125         struct timespec ts1,ts2;
2126         double timediff;
2127
2128         clock_gettime_mono(&ts1);
2129         result = SMB_VFS_NEXT_LISTXATTR(handle, path, list, size);
2130         clock_gettime_mono(&ts2);
2131         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2132
2133         if (timediff > audit_timeout) {
2134                 smb_time_audit_log_fname("listxattr", timediff, path);
2135         }
2136
2137         return result;
2138 }
2139
2140 static ssize_t smb_time_audit_flistxattr(struct vfs_handle_struct *handle,
2141                                          struct files_struct *fsp, char *list,
2142                                          size_t size)
2143 {
2144         ssize_t result;
2145         struct timespec ts1,ts2;
2146         double timediff;
2147
2148         clock_gettime_mono(&ts1);
2149         result = SMB_VFS_NEXT_FLISTXATTR(handle, fsp, list, size);
2150         clock_gettime_mono(&ts2);
2151         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2152
2153         if (timediff > audit_timeout) {
2154                 smb_time_audit_log_fsp("flistxattr", timediff, fsp);
2155         }
2156
2157         return result;
2158 }
2159
2160 static int smb_time_audit_removexattr(struct vfs_handle_struct *handle,
2161                                       const char *path, const char *name)
2162 {
2163         int result;
2164         struct timespec ts1,ts2;
2165         double timediff;
2166
2167         clock_gettime_mono(&ts1);
2168         result = SMB_VFS_NEXT_REMOVEXATTR(handle, path, name);
2169         clock_gettime_mono(&ts2);
2170         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2171
2172         if (timediff > audit_timeout) {
2173                 smb_time_audit_log_fname("removexattr", timediff, path);
2174         }
2175
2176         return result;
2177 }
2178
2179 static int smb_time_audit_fremovexattr(struct vfs_handle_struct *handle,
2180                                        struct files_struct *fsp,
2181                                        const char *name)
2182 {
2183         int result;
2184         struct timespec ts1,ts2;
2185         double timediff;
2186
2187         clock_gettime_mono(&ts1);
2188         result = SMB_VFS_NEXT_FREMOVEXATTR(handle, fsp, name);
2189         clock_gettime_mono(&ts2);
2190         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2191
2192         if (timediff > audit_timeout) {
2193                 smb_time_audit_log_fsp("fremovexattr", timediff, fsp);
2194         }
2195
2196         return result;
2197 }
2198
2199 static int smb_time_audit_setxattr(struct vfs_handle_struct *handle,
2200                                    const char *path, const char *name,
2201                                    const void *value, size_t size,
2202                                    int flags)
2203 {
2204         int result;
2205         struct timespec ts1,ts2;
2206         double timediff;
2207
2208         clock_gettime_mono(&ts1);
2209         result = SMB_VFS_NEXT_SETXATTR(handle, path, name, value, size,
2210                                        flags);
2211         clock_gettime_mono(&ts2);
2212         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2213
2214         if (timediff > audit_timeout) {
2215                 smb_time_audit_log_fname("setxattr", timediff, path);
2216         }
2217
2218         return result;
2219 }
2220
2221 static int smb_time_audit_fsetxattr(struct vfs_handle_struct *handle,
2222                                     struct files_struct *fsp, const char *name,
2223                                     const void *value, size_t size, int flags)
2224 {
2225         int result;
2226         struct timespec ts1,ts2;
2227         double timediff;
2228
2229         clock_gettime_mono(&ts1);
2230         result = SMB_VFS_NEXT_FSETXATTR(handle, fsp, name, value, size, flags);
2231         clock_gettime_mono(&ts2);
2232         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2233
2234         if (timediff > audit_timeout) {
2235                 smb_time_audit_log_fsp("fsetxattr", timediff, fsp);
2236         }
2237
2238         return result;
2239 }
2240
2241 static bool smb_time_audit_aio_force(struct vfs_handle_struct *handle,
2242                                      struct files_struct *fsp)
2243 {
2244         bool result;
2245         struct timespec ts1,ts2;
2246         double timediff;
2247
2248         clock_gettime_mono(&ts1);
2249         result = SMB_VFS_NEXT_AIO_FORCE(handle, fsp);
2250         clock_gettime_mono(&ts2);
2251         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2252
2253         if (timediff > audit_timeout) {
2254                 smb_time_audit_log_fsp("aio_force", timediff, fsp);
2255         }
2256
2257         return result;
2258 }
2259
2260 static bool smb_time_audit_is_offline(struct vfs_handle_struct *handle,
2261                                       const struct smb_filename *fname,
2262                                       SMB_STRUCT_STAT *sbuf)
2263 {
2264         bool result;
2265         struct timespec ts1,ts2;
2266         double timediff;
2267
2268         clock_gettime_mono(&ts1);
2269         result = SMB_VFS_NEXT_IS_OFFLINE(handle, fname, sbuf);
2270         clock_gettime_mono(&ts2);
2271         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2272
2273         if (timediff > audit_timeout) {
2274                 smb_time_audit_log_smb_fname("is_offline", timediff, fname);
2275         }
2276
2277         return result;
2278 }
2279
2280 static int smb_time_audit_set_offline(struct vfs_handle_struct *handle,
2281                                       const struct smb_filename *fname)
2282 {
2283         int result;
2284         struct timespec ts1,ts2;
2285         double timediff;
2286
2287         clock_gettime_mono(&ts1);
2288         result = SMB_VFS_NEXT_SET_OFFLINE(handle, fname);
2289         clock_gettime_mono(&ts2);
2290         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2291
2292         if (timediff > audit_timeout) {
2293                 smb_time_audit_log_smb_fname("set_offline", timediff, fname);
2294         }
2295
2296         return result;
2297 }
2298
2299 static NTSTATUS smb_time_audit_durable_cookie(struct vfs_handle_struct *handle,
2300                                               struct files_struct *fsp,
2301                                               TALLOC_CTX *mem_ctx,
2302                                               DATA_BLOB *cookie)
2303 {
2304         NTSTATUS result;
2305         struct timespec ts1,ts2;
2306         double timediff;
2307
2308         clock_gettime_mono(&ts1);
2309         result = SMB_VFS_NEXT_DURABLE_COOKIE(handle, fsp, mem_ctx, cookie);
2310         clock_gettime_mono(&ts2);
2311         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2312
2313         if (timediff > audit_timeout) {
2314                 smb_time_audit_log_fsp("durable_cookie", timediff, fsp);
2315         }
2316
2317         return result;
2318 }
2319
2320 static NTSTATUS smb_time_audit_durable_disconnect(struct vfs_handle_struct *handle,
2321                                                   struct files_struct *fsp,
2322                                                   const DATA_BLOB old_cookie,
2323                                                   TALLOC_CTX *mem_ctx,
2324                                                   DATA_BLOB *new_cookie)
2325 {
2326         NTSTATUS result;
2327         struct timespec ts1,ts2;
2328         double timediff;
2329
2330         clock_gettime_mono(&ts1);
2331         result = SMB_VFS_NEXT_DURABLE_DISCONNECT(handle, fsp, old_cookie,
2332                                                  mem_ctx, new_cookie);
2333         clock_gettime_mono(&ts2);
2334         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2335
2336         if (timediff > audit_timeout) {
2337                 smb_time_audit_log_fsp("durable_disconnect", timediff, fsp);
2338         }
2339
2340         return result;
2341 }
2342
2343 static NTSTATUS smb_time_audit_durable_reconnect(struct vfs_handle_struct *handle,
2344                                                  struct smb_request *smb1req,
2345                                                  struct smbXsrv_open *op,
2346                                                  const DATA_BLOB old_cookie,
2347                                                  TALLOC_CTX *mem_ctx,
2348                                                  struct files_struct **fsp,
2349                                                  DATA_BLOB *new_cookie)
2350 {
2351         NTSTATUS result;
2352         struct timespec ts1,ts2;
2353         double timediff;
2354
2355         clock_gettime_mono(&ts1);
2356         result = SMB_VFS_NEXT_DURABLE_RECONNECT(handle, smb1req, op, old_cookie,
2357                                                 mem_ctx, fsp, new_cookie);
2358         clock_gettime_mono(&ts2);
2359         timediff = nsec_time_diff(&ts2,&ts1)*1.0e-9;
2360
2361         if (timediff > audit_timeout) {
2362                 smb_time_audit_log("durable_reconnect", timediff);
2363         }
2364
2365         return result;
2366 }
2367
2368 /* VFS operations */
2369
2370 static struct vfs_fn_pointers vfs_time_audit_fns = {
2371         .connect_fn = smb_time_audit_connect,
2372         .disconnect_fn = smb_time_audit_disconnect,
2373         .disk_free_fn = smb_time_audit_disk_free,
2374         .get_quota_fn = smb_time_audit_get_quota,
2375         .set_quota_fn = smb_time_audit_set_quota,
2376         .get_shadow_copy_data_fn = smb_time_audit_get_shadow_copy_data,
2377         .statvfs_fn = smb_time_audit_statvfs,
2378         .fs_capabilities_fn = smb_time_audit_fs_capabilities,
2379         .opendir_fn = smb_time_audit_opendir,
2380         .fdopendir_fn = smb_time_audit_fdopendir,
2381         .readdir_fn = smb_time_audit_readdir,
2382         .seekdir_fn = smb_time_audit_seekdir,
2383         .telldir_fn = smb_time_audit_telldir,
2384         .rewind_dir_fn = smb_time_audit_rewinddir,
2385         .mkdir_fn = smb_time_audit_mkdir,
2386         .rmdir_fn = smb_time_audit_rmdir,
2387         .closedir_fn = smb_time_audit_closedir,
2388         .init_search_op_fn = smb_time_audit_init_search_op,
2389         .open_fn = smb_time_audit_open,
2390         .create_file_fn = smb_time_audit_create_file,
2391         .close_fn = smb_time_audit_close,
2392         .read_fn = smb_time_audit_read,
2393         .pread_fn = smb_time_audit_pread,
2394         .pread_send_fn = smb_time_audit_pread_send,
2395         .pread_recv_fn = smb_time_audit_pread_recv,
2396         .write_fn = smb_time_audit_write,
2397         .pwrite_fn = smb_time_audit_pwrite,
2398         .pwrite_send_fn = smb_time_audit_pwrite_send,
2399         .pwrite_recv_fn = smb_time_audit_pwrite_recv,
2400         .lseek_fn = smb_time_audit_lseek,
2401         .sendfile_fn = smb_time_audit_sendfile,
2402         .recvfile_fn = smb_time_audit_recvfile,
2403         .rename_fn = smb_time_audit_rename,
2404         .fsync_fn = smb_time_audit_fsync,
2405         .fsync_send_fn = smb_time_audit_fsync_send,
2406         .fsync_recv_fn = smb_time_audit_fsync_recv,
2407         .stat_fn = smb_time_audit_stat,
2408         .fstat_fn = smb_time_audit_fstat,
2409         .lstat_fn = smb_time_audit_lstat,
2410         .get_alloc_size_fn = smb_time_audit_get_alloc_size,
2411         .unlink_fn = smb_time_audit_unlink,
2412         .chmod_fn = smb_time_audit_chmod,
2413         .fchmod_fn = smb_time_audit_fchmod,
2414         .chown_fn = smb_time_audit_chown,
2415         .fchown_fn = smb_time_audit_fchown,
2416         .lchown_fn = smb_time_audit_lchown,
2417         .chdir_fn = smb_time_audit_chdir,
2418         .getwd_fn = smb_time_audit_getwd,
2419         .ntimes_fn = smb_time_audit_ntimes,
2420         .ftruncate_fn = smb_time_audit_ftruncate,
2421         .fallocate_fn = smb_time_audit_fallocate,
2422         .lock_fn = smb_time_audit_lock,
2423         .kernel_flock_fn = smb_time_audit_kernel_flock,
2424         .linux_setlease_fn = smb_time_audit_linux_setlease,
2425         .getlock_fn = smb_time_audit_getlock,
2426         .symlink_fn = smb_time_audit_symlink,
2427         .readlink_fn = smb_time_audit_readlink,
2428         .link_fn = smb_time_audit_link,
2429         .mknod_fn = smb_time_audit_mknod,
2430         .realpath_fn = smb_time_audit_realpath,
2431         .notify_watch_fn = smb_time_audit_notify_watch,
2432         .chflags_fn = smb_time_audit_chflags,
2433         .file_id_create_fn = smb_time_audit_file_id_create,
2434         .streaminfo_fn = smb_time_audit_streaminfo,
2435         .get_real_filename_fn = smb_time_audit_get_real_filename,
2436         .connectpath_fn = smb_time_audit_connectpath,
2437         .brl_lock_windows_fn = smb_time_audit_brl_lock_windows,
2438         .brl_unlock_windows_fn = smb_time_audit_brl_unlock_windows,
2439         .brl_cancel_windows_fn = smb_time_audit_brl_cancel_windows,
2440         .strict_lock_fn = smb_time_audit_strict_lock,
2441         .strict_unlock_fn = smb_time_audit_strict_unlock,
2442         .translate_name_fn = smb_time_audit_translate_name,
2443         .copy_chunk_send_fn = smb_time_audit_copy_chunk_send,
2444         .copy_chunk_recv_fn = smb_time_audit_copy_chunk_recv,
2445         .get_compression_fn = smb_time_audit_get_compression,
2446         .set_compression_fn = smb_time_audit_set_compression,
2447         .readdir_attr_fn = smb_time_audit_readdir_attr,
2448         .fget_nt_acl_fn = smb_time_audit_fget_nt_acl,
2449         .get_nt_acl_fn = smb_time_audit_get_nt_acl,
2450         .fset_nt_acl_fn = smb_time_audit_fset_nt_acl,
2451         .chmod_acl_fn = smb_time_audit_chmod_acl,
2452         .fchmod_acl_fn = smb_time_audit_fchmod_acl,
2453         .sys_acl_get_file_fn = smb_time_audit_sys_acl_get_file,
2454         .sys_acl_get_fd_fn = smb_time_audit_sys_acl_get_fd,
2455         .sys_acl_blob_get_file_fn = smb_time_audit_sys_acl_blob_get_file,
2456         .sys_acl_blob_get_fd_fn = smb_time_audit_sys_acl_blob_get_fd,
2457         .sys_acl_set_file_fn = smb_time_audit_sys_acl_set_file,
2458         .sys_acl_set_fd_fn = smb_time_audit_sys_acl_set_fd,
2459         .sys_acl_delete_def_file_fn = smb_time_audit_sys_acl_delete_def_file,
2460         .getxattr_fn = smb_time_audit_getxattr,
2461         .fgetxattr_fn = smb_time_audit_fgetxattr,
2462         .listxattr_fn = smb_time_audit_listxattr,
2463         .flistxattr_fn = smb_time_audit_flistxattr,
2464         .removexattr_fn = smb_time_audit_removexattr,
2465         .fremovexattr_fn = smb_time_audit_fremovexattr,
2466         .setxattr_fn = smb_time_audit_setxattr,
2467         .fsetxattr_fn = smb_time_audit_fsetxattr,
2468         .aio_force_fn = smb_time_audit_aio_force,
2469         .is_offline_fn = smb_time_audit_is_offline,
2470         .set_offline_fn = smb_time_audit_set_offline,
2471         .durable_cookie_fn = smb_time_audit_durable_cookie,
2472         .durable_disconnect_fn = smb_time_audit_durable_disconnect,
2473         .durable_reconnect_fn = smb_time_audit_durable_reconnect,
2474 };
2475
2476
2477 NTSTATUS vfs_time_audit_init(void);
2478 NTSTATUS vfs_time_audit_init(void)
2479 {
2480         audit_timeout = (double)lp_parm_int(-1, "time_audit", "timeout",
2481                                             10000) / 1000.0;
2482         return smb_register_vfs(SMB_VFS_INTERFACE_VERSION, "time_audit",
2483                                 &vfs_time_audit_fns);
2484 }