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