source4/torture/util_writetime.c

   1 /*
   2    Unix SMB/CIFS implementation.
   3
   4    test suite for delayed write time updates
   5
   6    Copyright (C) Stefan Metzmacher 2018
   7
   8    This program is free software; you can redistribute it and/or modify
   9    it under the terms of the GNU General Public License as published by
  10    the Free Software Foundation; either version 3 of the License, or
  11    (at your option) any later version.
  12
  13    This program is distributed in the hope that it will be useful,
  14    but WITHOUT ANY WARRANTY; without even the implied warranty of
  15    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  16    GNU General Public License for more details.
  17
  18    You should have received a copy of the GNU General Public License
  19    along with this program.  If not, see <http://www.gnu.org/licenses/>.
  20 */
  21
  22 #include "includes.h"
  23 #include "../lib/util/time_basic.h"
  24 #include "../libcli/smb/smb_common.h"
  25 #include "../libcli/smb/smbXcli_base.h"
  26 #include "libcli/raw/libcliraw.h"
  27 #include "torture/torture.h"
  28 #include "torture/util.h"
  29
  30 #define COMPARE_TIME_CMP(given, gelem, correct, celem, cmp) do { \
  31         const uint64_t _r = 10*1000*1000; \
  32         NTTIME _g = (given).basic_info.out.gelem; \
  33         NTTIME _gr = (_g / _r) * _r; \
  34         NTTIME _c = (correct).basic_info.out.celem; \
  35         NTTIME _cr = (_c / _r) * _r; \
  36         bool _strict = torture_setting_bool(tctx, "strict mode", false); \
  37         const char *_err = NULL; \
  38         if (_strict && (_g cmp _c)) { \
  39                 _err = "strict"; \
  40         } else if ((_g cmp _c) && (_gr cmp _cr)) { \
  41                 /* handle filesystem without high resolution timestamps */ \
  42                 _err = "rounded"; \
  43         } \
  44         if (_err != NULL) { \
  45                 struct timeval _gtv; \
  46                 struct timeval _ctv; \
  47                 struct timeval_buf _gtvb; \
  48                 struct timeval_buf _ctvb; \
  49                 nttime_to_timeval(&_gtv, _g); \
  50                 nttime_to_timeval(&_ctv, _c); \
  51                 torture_result(tctx, TORTURE_FAIL, \
  52                                __location__": %s wrong (%s.%s)%s %s (%s.%s)%s", \
  53                                _err, \
  54                                #given, #gelem, \
  55                                timeval_str_buf(&_gtv, false, true, &_gtvb), \
  56                                #cmp, \
  57                                #correct, #celem, \
  58                                timeval_str_buf(&_ctv, false, true, &_ctvb)); \
  59                 ret = false; \
  60                 goto done; \
  61         } \
  62 } while (0)
  63 #define COMPARE_WRITE_TIME_CMP(given, correct, cmp) do { \
  64         COMPARE_TIME_CMP(given, write_time, correct, write_time, cmp); \
  65 } while (0)
  66 #define COMPARE_WRITE_TIME_EQUAL(given,correct) \
  67         COMPARE_WRITE_TIME_CMP(given,correct,!=)
  68 #define COMPARE_WRITE_TIME_GREATER(given,correct) \
  69         COMPARE_WRITE_TIME_CMP(given,correct,<=)
  70
  71 #define COMPARE_ACCESS_TIME_CMP(given, correct, cmp) do { \
  72         COMPARE_TIME_CMP(given, access_time, correct, access_time, cmp); \
  73 } while (0)
  74 #define COMPARE_ACCESS_TIME_EQUAL(given,correct) \
  75         COMPARE_ACCESS_TIME_CMP(given,correct,!=)
  76 #define COMPARE_ACCESS_TIME_GREATER(given,correct) \
  77         COMPARE_ACCESS_TIME_CMP(given,correct,<=)
  78
  79 #define COMPARE_CHANGE_TIME_CMP(given, correct, cmp) do { \
  80         COMPARE_TIME_CMP(given, change_time, correct, change_time, cmp); \
  81 } while (0)
  82 #define COMPARE_CHANGE_TIME_EQUAL(given,correct) \
  83         COMPARE_CHANGE_TIME_CMP(given,correct,!=)
  84 #define COMPARE_CHANGE_TIME_GREATER(given,correct) \
  85         COMPARE_CHANGE_TIME_CMP(given,correct,<=)
  86
  87 #define COMPARE_CREATE_TIME_CMP(given, correct, cmp) do { \
  88         COMPARE_TIME_CMP(given, create_time, correct, create_time, cmp); \
  89 } while (0)
  90 #define COMPARE_CREATE_TIME_EQUAL(given,correct) \
  91         COMPARE_CREATE_TIME_CMP(given,correct,!=)
  92
  93 #define COMPARE_ALL_TIMES_EQUAL(given,correct) do { \
  94         COMPARE_WRITE_TIME_EQUAL(given,correct); \
  95         COMPARE_CHANGE_TIME_EQUAL(given,correct); \
  96         COMPARE_ACCESS_TIME_EQUAL(given,correct); \
  97         COMPARE_CREATE_TIME_EQUAL(given,correct); \
  98 } while (0)
  99
 100 #define COMPARE_TIMES_AFTER_WRITE(given,correct) do { \
 101         COMPARE_WRITE_TIME_GREATER(given,correct); \
 102         COMPARE_CHANGE_TIME_GREATER(given,correct); \
 103         COMPARE_ACCESS_TIME_EQUAL(given,correct); \
 104         COMPARE_CREATE_TIME_EQUAL(given,correct); \
 105         COMPARE_TIME_CMP(given, change_time, given, write_time, !=); \
 106 } while (0)
 107
 108 #define COMPARE_TIMES_AFTER_CLOSE(given,correct) do { \
 109         COMPARE_WRITE_TIME_GREATER(given,correct); \
 110         COMPARE_CHANGE_TIME_GREATER(given,correct); \
 111         COMPARE_ACCESS_TIME_GREATER(given,correct); \
 112         COMPARE_CREATE_TIME_EQUAL(given,correct); \
 113         COMPARE_TIME_CMP(given, change_time, given, write_time, !=); \
 114         COMPARE_TIME_CMP(given, access_time, given, write_time, !=); \
 115 } while (0)
 116
 117 bool test_delay_writetime1(struct torture_context *tctx,
 118                            double used_delay,
 119                            double normal_delay,
 120                            const char *description,
 121                            bool (*get_basic_info_cb)(void *private_data,
 122                                                      union smb_fileinfo *finfo),
 123                            bool (*write_data_cb)(void *private_data),
 124                            bool (*close_cb)(void *private_data,
 125                                             union smb_fileinfo *finfo),
 126                            void *private_data)
 127 {
 128         union smb_fileinfo finfo0, finfo1, finfo2, finfo3, finfoT;
 129         struct timeval before_write;
 130         struct timeval after_write;
 131         struct timeval before_last_write;
 132         struct timeval after_last_write;
 133         struct timeval start;
 134         struct timeval end;
 135         double sec = used_delay / normal_delay;
 136         double msec = 1000 * sec;
 137         double nsec = 1000 * msec;
 138         double expected_delay = used_delay / nsec;
 139         double min_delay = expected_delay * 0.01;
 140         double max_delay = 5 * expected_delay;
 141         bool ret = true;
 142         bool ok;
 143
 144         torture_comment(tctx, "START: %s\n", description);
 145
 146         /* get the initial times */
 147         ok = get_basic_info_cb(private_data, &finfo0);
 148         torture_assert(tctx, ok, "get_basic_info_cb: finfo0");
 149
 150         /*
 151          * Make sure the time doesn't change during the next 5 seconds
 152          */
 153         start = timeval_current();
 154         end = timeval_add(&start, max_delay * 1.25, 0);
 155         while (!timeval_expired(&end)) {
 156                 smb_msleep(1 * msec);
 157                 torture_comment(tctx, "Check for no change\n");
 158                 ok = get_basic_info_cb(private_data, &finfoT);
 159                 torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
 160                 COMPARE_ALL_TIMES_EQUAL(finfoT, finfo0);
 161         }
 162
 163         ok = get_basic_info_cb(private_data, &finfoT);
 164         torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
 165         COMPARE_WRITE_TIME_EQUAL(finfoT, finfo0);
 166
 167         torture_comment(tctx, "Do a write on the file handle\n");
 168         before_write = timeval_current();
 169         ok = write_data_cb(private_data);
 170         after_write = timeval_current();
 171         torture_assert(tctx, ok, "write_data_cb");
 172
 173         start = timeval_current();
 174         end = timeval_add(&start, max_delay * 2, 0);
 175         while (!timeval_expired(&end)) {
 176                 struct timeval before_get;
 177                 struct timeval after_get;
 178
 179                 torture_comment(tctx, "Wait for change\n");
 180                 before_get = timeval_current();
 181                 ok = get_basic_info_cb(private_data, &finfoT);
 182                 after_get = timeval_current();
 183                 torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
 184
 185                 if (finfoT.basic_info.out.write_time > finfo0.basic_info.out.write_time) {
 186                         double delayS = timeval_elapsed2(&after_write, &before_get);
 187                         double delayL = timeval_elapsed2(&before_write, &after_get);
 188
 189                         torture_comment(tctx, "Server updated write_time after %.2f/%.2f seconds "
 190                                         "(min delay == %.2f, max delay == %.2f)\n",
 191                                         delayS, delayL, min_delay, max_delay);
 192                         torture_assert(tctx, (delayL >= min_delay),
 193                                        "Server updated write_time to early!");
 194                         torture_assert(tctx, (delayS <= max_delay),
 195                                        "Server didn't update write_time!");
 196
 197                         COMPARE_TIMES_AFTER_WRITE(finfoT, finfo0);
 198                         break;
 199                 }
 200
 201                 COMPARE_ALL_TIMES_EQUAL(finfoT, finfo0);
 202                 smb_msleep(0.01 * msec);
 203         }
 204
 205         ok = get_basic_info_cb(private_data, &finfo1);
 206         torture_assert(tctx, ok, "get_basic_info_cb: finfo1");
 207         COMPARE_TIMES_AFTER_WRITE(finfo1, finfo0);
 208
 209         /*
 210          * Make sure the time doesn't change during the next 5 seconds
 211          */
 212         start = timeval_current();
 213         end = timeval_add(&start, max_delay * 1.25, 0);
 214         while (!timeval_expired(&end)) {
 215                 smb_msleep(1 * msec);
 216                 torture_comment(tctx, "Check for no additional change\n");
 217                 ok = get_basic_info_cb(private_data, &finfoT);
 218                 torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
 219                 COMPARE_ALL_TIMES_EQUAL(finfoT, finfo1);
 220         }
 221
 222         ok = get_basic_info_cb(private_data, &finfoT);
 223         torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
 224         COMPARE_ALL_TIMES_EQUAL(finfoT, finfo1);
 225
 226         torture_comment(tctx, "Do a write on the file handle\n");
 227         before_write = timeval_current();
 228         ok = write_data_cb(private_data);
 229         after_write = timeval_current();
 230         torture_assert(tctx, ok, "write_data_cb");
 231
 232         ZERO_STRUCT(finfo2);
 233         before_last_write = before_write;
 234         after_last_write = after_write;
 235         start = timeval_current();
 236         end = timeval_add(&start, max_delay * 2, 0);
 237         while (!timeval_expired(&end)) {
 238                 struct timeval before_get;
 239                 struct timeval after_get;
 240
 241                 smb_msleep(0.01 * msec);
 242
 243                 torture_comment(tctx, "Wait for change\n");
 244                 before_get = timeval_current();
 245                 ok = get_basic_info_cb(private_data, &finfoT);
 246                 after_get = timeval_current();
 247                 torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
 248
 249                 if (finfoT.basic_info.out.write_time > finfo1.basic_info.out.write_time) {
 250                         double delayS = timeval_elapsed2(&after_write, &before_get);
 251                         double delayL = timeval_elapsed2(&before_write, &after_get);
 252
 253                         torture_comment(tctx, "Server updated write_time after %.2f/%.2f seconds "
 254                                         "(min delay == %.2f, max delay == %.2f)\n",
 255                                         delayS, delayL, min_delay, max_delay);
 256                         torture_assert(tctx, (delayL >= min_delay),
 257                                        "Server updated write_time to early!");
 258                         torture_assert(tctx, (delayS <= max_delay),
 259                                        "Server didn't update write_time!");
 260
 261                         COMPARE_TIMES_AFTER_WRITE(finfoT, finfo1);
 262                         before_write = before_last_write;
 263                         after_write = after_last_write;
 264                         finfo2 = finfoT;
 265                         break;
 266                 }
 267
 268                 COMPARE_ALL_TIMES_EQUAL(finfoT, finfo1);
 269
 270                 torture_comment(tctx, "Write while waiting\n");
 271                 before_last_write = timeval_current();
 272                 ok = write_data_cb(private_data);
 273                 after_last_write = timeval_current();
 274                 torture_assert(tctx, ok, "write_data_cb");
 275         }
 276
 277         // We may get one additional change...
 278
 279         ok = get_basic_info_cb(private_data, &finfo3);
 280         torture_assert(tctx, ok, "get_basic_info_cb: finfo3");
 281         COMPARE_ALL_TIMES_EQUAL(finfo3, finfo2);
 282
 283         /*
 284          * Make sure the time doesn't change during the next 5 seconds
 285          */
 286         start = timeval_current();
 287         end = timeval_add(&start, max_delay * 1.25, 0);
 288         while (!timeval_expired(&end)) {
 289                 smb_msleep(1 * msec);
 290                 torture_comment(tctx, "Check for no additional change\n");
 291                 ok = get_basic_info_cb(private_data, &finfoT);
 292                 torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
 293                 COMPARE_ALL_TIMES_EQUAL(finfoT, finfo3);
 294         }
 295
 296         ok = get_basic_info_cb(private_data, &finfoT);
 297         torture_assert(tctx, ok, "get_basic_info_cb: finfoT");
 298         COMPARE_ALL_TIMES_EQUAL(finfoT, finfo3);
 299
 300         if (close_cb == NULL) {
 301                 goto done;
 302         }
 303
 304         /*
 305          * the close updates the write time to the time of the close
 306          * and not to the time of the last write!
 307          */
 308         torture_comment(tctx, "Close the file handle\n");
 309
 310         ok = close_cb(private_data, &finfoT);
 311         torture_assert(tctx, ok, "close_cb: finfoT");
 312         COMPARE_ALL_TIMES_EQUAL(finfoT, finfo3);
 313
 314 done:
 315         return ret;
 316 }