r21707: Finally merge my (long-living) perlselftest branch.
[kai/samba.git] / source / torture / basic / delaywrite.c
1 /* 
2    Unix SMB/CIFS implementation.
3
4    test suite for delayed write update 
5
6    Copyright (C) Volker Lendecke 2004
7    Copyright (C) Andrew Tridgell 2004
8    Copyright (C) Jeremy Allison 2004
9    
10    This program is free software; you can redistribute it and/or modify
11    it under the terms of the GNU General Public License as published by
12    the Free Software Foundation; either version 2 of the License, or
13    (at your option) any later version.
14    
15    This program is distributed in the hope that it will be useful,
16    but WITHOUT ANY WARRANTY; without even the implied warranty of
17    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
18    GNU General Public License for more details.
19    
20    You should have received a copy of the GNU General Public License
21    along with this program; if not, write to the Free Software
22    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
23 */
24
25 #include "includes.h"
26 #include "torture/torture.h"
27 #include "libcli/raw/libcliraw.h"
28 #include "system/time.h"
29 #include "system/filesys.h"
30 #include "libcli/libcli.h"
31 #include "torture/util.h"
32
33 #define BASEDIR "\\delaywrite"
34
35 static BOOL test_delayed_write_update(struct torture_context *tctx, struct smbcli_state *cli)
36 {
37         union smb_fileinfo finfo1, finfo2;
38         const char *fname = BASEDIR "\\torture_file.txt";
39         NTSTATUS status;
40         int fnum1 = -1;
41         BOOL ret = True;
42         ssize_t written;
43         time_t t;
44
45         if (!torture_setup_dir(cli, BASEDIR)) {
46                 return False;
47         }
48
49         fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
50         if (fnum1 == -1) {
51                 torture_comment(tctx, "Failed to open %s\n", fname);
52                 return False;
53         }
54
55         finfo1.basic_info.level = RAW_FILEINFO_BASIC_INFO;
56         finfo1.basic_info.in.file.fnum = fnum1;
57         finfo2 = finfo1;
58
59         status = smb_raw_fileinfo(cli->tree, tctx, &finfo1);
60
61         if (!NT_STATUS_IS_OK(status)) {
62                 DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
63                 return False;
64         }
65         
66         torture_comment(tctx, "Initial write time %s\n", 
67                nt_time_string(tctx, finfo1.basic_info.out.write_time));
68
69         /* 3 second delay to ensure we get past any 2 second time
70            granularity (older systems may have that) */
71         sleep(3);
72
73         written =  smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
74
75         if (written != 1) {
76                 torture_comment(tctx, "write failed - wrote %d bytes (%s)\n", 
77                        (int)written, __location__);
78                 return False;
79         }
80
81         t = time(NULL);
82
83         while (time(NULL) < t+120) {
84                 status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
85
86                 if (!NT_STATUS_IS_OK(status)) {
87                         DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
88                         ret = False;
89                         break;
90                 }
91                 torture_comment(tctx, "write time %s\n", 
92                        nt_time_string(tctx, finfo2.basic_info.out.write_time));
93                 if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
94                         torture_comment(tctx, "Server updated write_time after %d seconds\n",
95                                (int)(time(NULL) - t));
96                         break;
97                 }
98                 sleep(1);
99                 fflush(stdout);
100         }
101         
102         if (finfo1.basic_info.out.write_time == finfo2.basic_info.out.write_time) {
103                 torture_comment(tctx, "Server did not update write time?!\n");
104                 ret = False;
105         }
106
107
108         if (fnum1 != -1)
109                 smbcli_close(cli->tree, fnum1);
110         smbcli_unlink(cli->tree, fname);
111         smbcli_deltree(cli->tree, BASEDIR);
112
113         return ret;
114 }
115
116 /* 
117  * Do as above, but using 2 connections.
118  */
119
120 static BOOL test_delayed_write_update2(struct torture_context *tctx, struct smbcli_state *cli, 
121                                                                            struct smbcli_state *cli2)
122 {
123         union smb_fileinfo finfo1, finfo2;
124         const char *fname = BASEDIR "\\torture_file.txt";
125         NTSTATUS status;
126         int fnum1 = -1;
127         int fnum2 = -1;
128         BOOL ret = True;
129         ssize_t written;
130         time_t t;
131         union smb_flush flsh;
132
133         if (!torture_setup_dir(cli, BASEDIR)) {
134                 return False;
135         }
136
137         fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
138         if (fnum1 == -1) {
139                 torture_comment(tctx, "Failed to open %s\n", fname);
140                 return False;
141         }
142
143         finfo1.basic_info.level = RAW_FILEINFO_BASIC_INFO;
144         finfo1.basic_info.in.file.fnum = fnum1;
145         finfo2 = finfo1;
146
147         status = smb_raw_fileinfo(cli->tree, tctx, &finfo1);
148
149         if (!NT_STATUS_IS_OK(status)) {
150                 DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
151                 return False;
152         }
153         
154         torture_comment(tctx, "Initial write time %s\n", 
155                nt_time_string(tctx, finfo1.basic_info.out.write_time));
156
157         /* 3 second delay to ensure we get past any 2 second time
158            granularity (older systems may have that) */
159         sleep(3);
160
161         {
162                 /* Try using setfileinfo instead of write to update write time. */
163                 union smb_setfileinfo sfinfo;
164                 time_t t_set = time(NULL);
165                 sfinfo.basic_info.level = RAW_SFILEINFO_BASIC_INFO;
166                 sfinfo.basic_info.in.file.fnum = fnum1;
167                 sfinfo.basic_info.in.create_time = finfo1.basic_info.out.create_time;
168                 sfinfo.basic_info.in.access_time = finfo1.basic_info.out.access_time;
169
170                 /* I tried this with both + and - ve to see if it makes a different.
171                    It doesn't - once the filetime is set via setfileinfo it stays that way. */
172 #if 1
173                 unix_to_nt_time(&sfinfo.basic_info.in.write_time, t_set - 30000);
174 #else
175                 unix_to_nt_time(&sfinfo.basic_info.in.write_time, t_set + 30000);
176 #endif
177                 sfinfo.basic_info.in.change_time = finfo1.basic_info.out.change_time;
178                 sfinfo.basic_info.in.attrib = finfo1.basic_info.out.attrib;
179
180                 status = smb_raw_setfileinfo(cli->tree, &sfinfo);
181
182                 if (!NT_STATUS_IS_OK(status)) {
183                         DEBUG(0, ("sfileinfo failed: %s\n", nt_errstr(status)));
184                         return False;
185                 }
186         }
187
188         t = time(NULL);
189
190         while (time(NULL) < t+120) {
191                 finfo2.basic_info.in.file.path = fname;
192         
193                 status = smb_raw_pathinfo(cli2->tree, tctx, &finfo2);
194
195                 if (!NT_STATUS_IS_OK(status)) {
196                         DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
197                         ret = False;
198                         break;
199                 }
200                 torture_comment(tctx, "write time %s\n", 
201                        nt_time_string(tctx, finfo2.basic_info.out.write_time));
202                 if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
203                         torture_comment(tctx, "Server updated write_time after %d seconds\n",
204                                (int)(time(NULL) - t));
205                         break;
206                 }
207                 sleep(1);
208                 fflush(stdout);
209         }
210         
211         if (finfo1.basic_info.out.write_time == finfo2.basic_info.out.write_time) {
212                 torture_comment(tctx, "Server did not update write time?!\n");
213                 ret = False;
214         }
215
216         /* Now try a write to see if the write time gets reset. */
217
218         finfo1.basic_info.level = RAW_FILEINFO_BASIC_INFO;
219         finfo1.basic_info.in.file.fnum = fnum1;
220         finfo2 = finfo1;
221
222         status = smb_raw_fileinfo(cli->tree, tctx, &finfo1);
223
224         if (!NT_STATUS_IS_OK(status)) {
225                 DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
226                 return False;
227         }
228         
229         torture_comment(tctx, "Modified write time %s\n", 
230                nt_time_string(tctx, finfo1.basic_info.out.write_time));
231
232
233         torture_comment(tctx, "Doing a 10 byte write to extend the file and see if this changes the last write time.\n");
234
235         written =  smbcli_write(cli->tree, fnum1, 0, "0123456789", 1, 10);
236
237         if (written != 10) {
238                 torture_comment(tctx, "write failed - wrote %d bytes (%s)\n", 
239                        (int)written, __location__);
240                 return False;
241         }
242
243         /* Just to prove to tridge that the an smbflush has no effect on
244            the write time :-). The setfileinfo IS STICKY. JRA. */
245
246         torture_comment(tctx, "Doing flush after write\n");
247
248         flsh.flush.level        = RAW_FLUSH_FLUSH;
249         flsh.flush.in.file.fnum = fnum1;
250         status = smb_raw_flush(cli->tree, &flsh);
251         if (!NT_STATUS_IS_OK(status)) {
252                 DEBUG(0, ("smbflush failed: %s\n", nt_errstr(status)));
253                 return False;
254         }
255
256         t = time(NULL);
257
258         /* Once the time was set using setfileinfo then it stays set - writes
259            don't have any effect. But make sure. */
260
261         while (time(NULL) < t+15) {
262                 status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
263
264                 if (!NT_STATUS_IS_OK(status)) {
265                         DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
266                         ret = False;
267                         break;
268                 }
269                 torture_comment(tctx, "write time %s\n", 
270                        nt_time_string(tctx, finfo2.basic_info.out.write_time));
271                 if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
272                         torture_comment(tctx, "Server updated write_time after %d seconds\n",
273                                (int)(time(NULL) - t));
274                         break;
275                 }
276                 sleep(1);
277                 fflush(stdout);
278         }
279         
280         if (finfo1.basic_info.out.write_time == finfo2.basic_info.out.write_time) {
281                 torture_comment(tctx, "Server did not update write time\n");
282         }
283
284         fnum2 = smbcli_open(cli->tree, fname, O_RDWR, DENY_NONE);
285         if (fnum2 == -1) {
286                 torture_comment(tctx, "Failed to open %s\n", fname);
287                 return False;
288         }
289         
290         torture_comment(tctx, "Doing a 10 byte write to extend the file via second fd and see if this changes the last write time.\n");
291
292         written =  smbcli_write(cli->tree, fnum2, 0, "0123456789", 11, 10);
293
294         if (written != 10) {
295                 torture_comment(tctx, "write failed - wrote %d bytes (%s)\n", 
296                        (int)written, __location__);
297                 return False;
298         }
299
300         status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
301
302         if (!NT_STATUS_IS_OK(status)) {
303                 DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
304                 return False;
305         }
306         torture_comment(tctx, "write time %s\n", 
307                nt_time_string(tctx, finfo2.basic_info.out.write_time));
308         if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
309                 torture_comment(tctx, "Server updated write_time\n");
310         }
311
312         torture_comment(tctx, "Closing the first fd to see if write time updated.\n");
313         smbcli_close(cli->tree, fnum1);
314         fnum1 = -1;
315
316         torture_comment(tctx, "Doing a 10 byte write to extend the file via second fd and see if this changes the last write time.\n");
317
318         written =  smbcli_write(cli->tree, fnum2, 0, "0123456789", 21, 10);
319
320         if (written != 10) {
321                 torture_comment(tctx, "write failed - wrote %d bytes (%s)\n", 
322                        (int)written, __location__);
323                 return False;
324         }
325
326         finfo1.basic_info.level = RAW_FILEINFO_BASIC_INFO;
327         finfo1.basic_info.in.file.fnum = fnum2;
328         finfo2 = finfo1;
329         status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
330
331         if (!NT_STATUS_IS_OK(status)) {
332                 DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
333                 return False;
334         }
335         torture_comment(tctx, "write time %s\n", 
336                nt_time_string(tctx, finfo2.basic_info.out.write_time));
337         if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
338                 torture_comment(tctx, "Server updated write_time\n");
339         }
340
341         t = time(NULL);
342
343         /* Once the time was set using setfileinfo then it stays set - writes
344            don't have any effect. But make sure. */
345
346         while (time(NULL) < t+15) {
347                 status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
348
349                 if (!NT_STATUS_IS_OK(status)) {
350                         DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
351                         ret = False;
352                         break;
353                 }
354                 torture_comment(tctx, "write time %s\n", 
355                        nt_time_string(tctx, finfo2.basic_info.out.write_time));
356                 if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
357                         torture_comment(tctx, "Server updated write_time after %d seconds\n",
358                                (int)(time(NULL) - t));
359                         break;
360                 }
361                 sleep(1);
362                 fflush(stdout);
363         }
364         
365         if (finfo1.basic_info.out.write_time == finfo2.basic_info.out.write_time) {
366                 torture_comment(tctx, "Server did not update write time\n");
367         }
368
369         torture_comment(tctx, "Closing both fd's to see if write time updated.\n");
370
371         smbcli_close(cli->tree, fnum2);
372         fnum2 = -1;
373
374         fnum1 = smbcli_open(cli->tree, fname, O_RDWR, DENY_NONE);
375         if (fnum1 == -1) {
376                 torture_comment(tctx, "Failed to open %s\n", fname);
377                 return False;
378         }
379
380         finfo1.basic_info.level = RAW_FILEINFO_BASIC_INFO;
381         finfo1.basic_info.in.file.fnum = fnum1;
382         finfo2 = finfo1;
383
384         status = smb_raw_fileinfo(cli->tree, tctx, &finfo1);
385
386         if (!NT_STATUS_IS_OK(status)) {
387                 DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
388                 return False;
389         }
390         
391         torture_comment(tctx, "Second open initial write time %s\n", 
392                nt_time_string(tctx, finfo1.basic_info.out.write_time));
393
394         sleep(10);
395         torture_comment(tctx, "Doing a 10 byte write to extend the file to see if this changes the last write time.\n");
396
397         written =  smbcli_write(cli->tree, fnum1, 0, "0123456789", 31, 10);
398
399         if (written != 10) {
400                 torture_comment(tctx, "write failed - wrote %d bytes (%s)\n", 
401                        (int)written, __location__);
402                 return False;
403         }
404
405         finfo1.basic_info.level = RAW_FILEINFO_BASIC_INFO;
406         finfo1.basic_info.in.file.fnum = fnum1;
407         finfo2 = finfo1;
408         status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
409
410         if (!NT_STATUS_IS_OK(status)) {
411                 DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
412                 return False;
413         }
414         torture_comment(tctx, "write time %s\n", 
415                nt_time_string(tctx, finfo2.basic_info.out.write_time));
416         if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
417                 torture_comment(tctx, "Server updated write_time\n");
418         }
419
420         t = time(NULL);
421
422         /* Once the time was set using setfileinfo then it stays set - writes
423            don't have any effect. But make sure. */
424
425         while (time(NULL) < t+15) {
426                 status = smb_raw_fileinfo(cli->tree, tctx, &finfo2);
427
428                 if (!NT_STATUS_IS_OK(status)) {
429                         DEBUG(0, ("fileinfo failed: %s\n", nt_errstr(status)));
430                         ret = False;
431                         break;
432                 }
433                 torture_comment(tctx, "write time %s\n", 
434                        nt_time_string(tctx, finfo2.basic_info.out.write_time));
435                 if (finfo1.basic_info.out.write_time != finfo2.basic_info.out.write_time) {
436                         torture_comment(tctx, "Server updated write_time after %d seconds\n",
437                                (int)(time(NULL) - t));
438                         break;
439                 }
440                 sleep(1);
441                 fflush(stdout);
442         }
443         
444         if (finfo1.basic_info.out.write_time == finfo2.basic_info.out.write_time) {
445                 torture_comment(tctx, "Server did not update write time\n");
446         }
447
448
449         /* One more test to do. We should read the filetime via findfirst on the
450            second connection to ensure it's the same. This is very easy for a Windows
451            server but a bastard to get right on a POSIX server. JRA. */
452
453         if (fnum1 != -1)
454                 smbcli_close(cli->tree, fnum1);
455         smbcli_unlink(cli->tree, fname);
456         smbcli_deltree(cli->tree, BASEDIR);
457
458         return ret;
459 }
460
461
462 /* Windows does obviously not update the stat info during a write call. I
463  * *think* this is the problem causing a spurious Excel 2003 on XP error
464  * message when saving a file. Excel does a setfileinfo, writes, and then does
465  * a getpath(!)info. Or so... For Samba sometimes it displays an error message
466  * that the file might have been changed in between. What i've been able to
467  * trace down is that this happens if the getpathinfo after the write shows a
468  * different last write time than the setfileinfo showed. This is really
469  * nasty....
470  */
471
472 static BOOL test_finfo_after_write(struct torture_context *tctx, struct smbcli_state *cli, 
473                                                                    struct smbcli_state *cli2)
474 {
475         union smb_fileinfo finfo1, finfo2;
476         const char *fname = BASEDIR "\\torture_file.txt";
477         NTSTATUS status;
478         int fnum1 = -1;
479         int fnum2;
480         BOOL ret = True;
481         ssize_t written;
482
483         if (!torture_setup_dir(cli, BASEDIR)) {
484                 return False;
485         }
486
487         fnum1 = smbcli_open(cli->tree, fname, O_RDWR|O_CREAT, DENY_NONE);
488         if (fnum1 == -1) {
489                 ret = False;
490                 torture_result(tctx, TORTURE_FAIL, __location__": unable to open %s", fname);
491                 goto done;
492         }
493
494         finfo1.basic_info.level = RAW_FILEINFO_BASIC_INFO;
495         finfo1.basic_info.in.file.fnum = fnum1;
496
497         status = smb_raw_fileinfo(cli->tree, tctx, &finfo1);
498
499         if (!NT_STATUS_IS_OK(status)) {
500                 ret = False;
501                 torture_result(tctx, TORTURE_FAIL, __location__": fileinfo failed: %s", nt_errstr(status));
502                 goto done;
503         }
504
505         msleep(1000);
506
507         written =  smbcli_write(cli->tree, fnum1, 0, "x", 0, 1);
508
509         if (written != 1) {
510                 torture_result(tctx, TORTURE_FAIL, __location__": written gave %d - should have been 1", (int)written);
511                 ret = False;
512                 goto done;
513         }
514
515         fnum2 = smbcli_open(cli2->tree, fname, O_RDWR, DENY_NONE);
516         if (fnum2 == -1) {
517                 torture_result(tctx, TORTURE_FAIL, __location__": failed to open 2nd time - %s", 
518                        smbcli_errstr(cli2->tree));
519                 ret = False;
520                 goto done;
521         }
522         
523         written =  smbcli_write(cli2->tree, fnum2, 0, "x", 0, 1);
524         
525         if (written != 1) {
526                 torture_result(tctx, TORTURE_FAIL, __location__": written gave %d - should have been 1", 
527                        (int)written);
528                 ret = False;
529                 goto done;
530         }
531         
532         finfo2.basic_info.level = RAW_FILEINFO_BASIC_INFO;
533         finfo2.basic_info.in.file.path = fname;
534         
535         status = smb_raw_pathinfo(cli2->tree, tctx, &finfo2);
536         
537         if (!NT_STATUS_IS_OK(status)) {
538                 torture_result(tctx, TORTURE_FAIL, __location__": fileinfo failed: %s", 
539                           nt_errstr(status));
540                 ret = False;
541                 goto done;
542         }
543         
544         if (finfo1.basic_info.out.create_time !=
545             finfo2.basic_info.out.create_time) {
546                 torture_result(tctx, TORTURE_FAIL, __location__": create_time changed");
547                 ret = False;
548                 goto done;
549         }
550         
551         if (finfo1.basic_info.out.access_time !=
552             finfo2.basic_info.out.access_time) {
553                 torture_result(tctx, TORTURE_FAIL, __location__": access_time changed");
554                 ret = False;
555                 goto done;
556         }
557         
558         if (finfo1.basic_info.out.write_time !=
559             finfo2.basic_info.out.write_time) {
560                 torture_result(tctx, TORTURE_FAIL, __location__": write_time changed:\n"
561                                            "write time conn 1 = %s, conn 2 = %s", 
562                        nt_time_string(tctx, finfo1.basic_info.out.write_time),
563                        nt_time_string(tctx, finfo2.basic_info.out.write_time));
564                 ret = False;
565                 goto done;
566         }
567         
568         if (finfo1.basic_info.out.change_time !=
569             finfo2.basic_info.out.change_time) {
570                 torture_result(tctx, TORTURE_FAIL, __location__": change_time changed");
571                 ret = False;
572                 goto done;
573         }
574         
575         /* One of the two following calls updates the qpathinfo. */
576         
577         /* If you had skipped the smbcli_write on fnum2, it would
578          * *not* have updated the stat on disk */
579         
580         smbcli_close(cli2->tree, fnum2);
581         cli2 = NULL;
582
583         /* This call is only for the people looking at ethereal :-) */
584         finfo2.basic_info.level = RAW_FILEINFO_BASIC_INFO;
585         finfo2.basic_info.in.file.path = fname;
586
587         status = smb_raw_pathinfo(cli->tree, tctx, &finfo2);
588
589         if (!NT_STATUS_IS_OK(status)) {
590                 torture_result(tctx, TORTURE_FAIL, __location__": fileinfo failed: %s", nt_errstr(status));
591                 ret = False;
592                 goto done;
593         }
594
595  done:
596         if (fnum1 != -1)
597                 smbcli_close(cli->tree, fnum1);
598         smbcli_unlink(cli->tree, fname);
599         smbcli_deltree(cli->tree, BASEDIR);
600
601         return ret;
602 }
603
604
605 /* 
606    testing of delayed update of write_time
607 */
608 struct torture_suite *torture_delay_write(void)
609 {
610         struct torture_suite *suite = torture_suite_create(talloc_autofree_context(), "DELAYWRITE");
611
612         torture_suite_add_2smb_test(suite, "finfo update on close", test_finfo_after_write);
613         torture_suite_add_1smb_test(suite, "delayed update of write time", test_delayed_write_update);
614         torture_suite_add_2smb_test(suite, "delayed update of write time using 2 connections", test_delayed_write_update2);
615
616         return suite;
617 }