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