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