source3/modules/vfs_time_audit.c

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