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