upstart

Merge lp:~jamesodhunt/upstart/bug-1447756-the-actual-fix into lp:upstart

  1. bug-1447756-the-actual-fix
  2. Merge into trunk
Proposed by James Hunt
Status: Merged
Merged at revision: 1666
Proposed branch: lp:~jamesodhunt/upstart/bug-1447756-the-actual-fix
Merge into: lp:upstart
Diff against target: 230 lines (+167/-3)
3 files modified
ChangeLog (+18/-0)
init/log.c (+42/-0)
init/tests/test_log.c (+107/-3)
To merge this branch: bzr merge lp:~jamesodhunt/upstart/bug-1447756-the-actual-fix
Reviewer Review Type Date Requested Status
Upstart Reviewers Pending
Review via email: mp+259020@code.launchpad.net

Description of the change

* init/log.c:
  - log_clear_unflushed(): Handle logs on the unflushed list which
    get flushed automatically by their corresponding NihIo before
    a request to clear the unflushed list is made. This scenario
    is triggered when a job which has spawned processes exits, but
    where the spawned processes continue to run and then produce
    output before the request to clear the unflushed list is made
    (at the time the log partition becomes writable) but after the
    log partition becomes writable (LP: #1447756).
* init/tests/test_log.c:
  - test_log_new(): Added new test:
    "ensure logger unflushed list ignores already flushed data".
  - test_log_destroy(): Improved test
     "ensure unflushed data moved to unflushed list with uid 0" by giving
    the log a parent and checking parent handling behaviour.

To post a comment you must log in.

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
=== modified file 'ChangeLog'
--- ChangeLog 2015-04-24 12:57:48 +0000
+++ ChangeLog 2015-05-13 15:53:09 +0000
@@ -1,3 +1,21 @@
12015-05-12 James Hunt <james.hunt@ubuntu.com>
2
3 * init/log.c:
4 - log_clear_unflushed(): Handle logs on the unflushed list which
5 get flushed automatically by their corresponding NihIo before
6 a request to clear the unflushed list is made. This scenario
7 is triggered when a job which has spawned processes exits, but
8 where the spawned processes continue to run and then produce
9 output before the request to clear the unflushed list is made
10 (at the time the log partition becomes writable) but after the
11 log partition becomes writable (LP: #1447756).
12 * init/tests/test_log.c:
13 - test_log_new(): Added new test:
14 "ensure logger unflushed list ignores already flushed data".
15 - test_log_destroy(): Improved test
16 "ensure unflushed data moved to unflushed list with uid 0" by giving
17 the log a parent and checking parent handling behaviour.
18
12015-04-24 James Hunt <james.hunt@ubuntu.com>192015-04-24 James Hunt <james.hunt@ubuntu.com>
220
3 * init/log.c:21 * init/log.c:
422
=== modified file 'init/log.c'
--- init/log.c 2015-04-24 12:57:48 +0000
+++ init/log.c 2015-05-13 15:53:09 +0000
@@ -802,6 +802,48 @@
802802
803 nih_assert (log);803 nih_assert (log);
804804
805 if (! log->unflushed->len) {
806 /* The job that originally owned this log has
807 * exited, but it spawned one or more other
808 * processes which still live on. If those
809 * processes produce output, the NihIo will get
810 * called automatically to flush the data.
811 * However, that happens asynchronously to
812 * clearing the unflushed list.
813 *
814 * Hence, if no unflushed data remains, remove
815 * the entry from the list.
816 *
817 * Note that doing so frees the log and stops
818 * any further output being logged from the
819 * out-of-job process(es). This isn't ideal
820 * however:
821 *
822 * - Better this than having the Log objects remain indefinately.
823 *
824 * - The problem is ultimately caused by a rogue
825 * job which should be fixed (see the warning
826 * that is produced for such jobs in
827 * log_read_watch()).
828 *
829 * - Even if the Log was retained, it would not
830 * be flushed unless multiple calls to this
831 * function are made (which is not going to
832 * occur by default).
833 *
834 * Note that it is necessary to set the io to
835 * NULL since it has already been freed by
836 * nih_io_closed(), but the io is not set to
837 * NULL. If we don't do this, when log_destroy()
838 * is called, it will attempt to dereference the
839 * already freed log->io.
840 */
841 log->io = NULL;
842 nih_free (elem);
843
844 continue;
845 }
846
805 /* To be added to this list, log should have been847 /* To be added to this list, log should have been
806 * detached from its parent job.848 * detached from its parent job.
807 */849 */
808850
=== modified file 'init/tests/test_log.c'
--- init/tests/test_log.c 2015-04-24 12:57:48 +0000
+++ init/tests/test_log.c 2015-05-13 15:53:09 +0000
@@ -654,6 +654,94 @@
654 TEST_FREE (log);654 TEST_FREE (log);
655655
656 /************************************************************/656 /************************************************************/
657 TEST_FEATURE ("ensure logger unflushed list ignores already flushed data");
658
659 /* Reset */
660 log_flushed = 0;
661
662 TEST_EQ (openpty (&pty_master, &pty_slave, NULL, NULL, NULL), 0);
663
664 TEST_GT (sprintf (filename, "%s/test.log", dirname), 0);
665
666 TEST_NE (log_unflushed_files, NULL);
667 TEST_TRUE (NIH_LIST_EMPTY (log_unflushed_files));
668
669 TEST_EQ (stat (dirname, &statbuf), 0);
670
671 /* Save */
672 old_perms = statbuf.st_mode;
673
674 /* Make file inaccessible */
675 TEST_EQ (chmod (dirname, 0x0), 0);
676
677 log = log_new (NULL, filename, pty_master, 0);
678 TEST_NE_P (log, NULL);
679
680 /* Write data to simulate a job process, but _DON'T_ close the
681 * fd (to simulate the job spawning another process which olds
682 * the fd open).
683 */
684 ret = write (pty_slave, str, strlen (str));
685 TEST_GT (ret, 0);
686 ret = write (pty_slave, "\n", 1);
687 TEST_EQ (ret, 1);
688
689 assert0 (log->unflushed->len);
690 TEST_EQ_P (log->unflushed->buf, NULL);
691
692 TEST_NE_P (log->io, NULL);
693
694 TEST_WATCH_UPDATE ();
695
696 /* nih_io_closed() should not have been called */
697 TEST_NE_P (log->io, NULL);
698
699 TEST_EQ_STR (log->unflushed->buf, "hello, world!\r\n");
700
701 /* +2 for '\r\n' */
702 TEST_EQ (log->unflushed->len, 2 + strlen (str));
703
704 /* Ensure no log file written */
705 TEST_LT (stat (filename, &statbuf), 0);
706
707 TEST_TRUE (NIH_LIST_EMPTY (log_unflushed_files));
708
709 TEST_FREE_TAG (log);
710
711 /* Force the usual code path for early boot on a normal system
712 * when a job produces output before the disks are writable.
713 */
714 log->open_errno = EROFS;
715
716 TEST_EQ (log_handle_unflushed (NULL, log), 0);
717
718 TEST_FALSE (NIH_LIST_EMPTY (log_unflushed_files));
719
720 /* Restore access */
721 TEST_EQ (chmod (dirname, old_perms), 0);
722
723 TEST_NE_P (log->io, NULL);
724
725 /* Simulate the data having already been flushed to disk
726 * and nih_io_closed() having been called.
727 */
728 log->io = NULL;
729 log->unflushed->len = 0;
730 log->unflushed->buf = NULL;
731 log->remote_closed = 1;
732
733 ret = log_clear_unflushed ();
734 TEST_EQ (ret, 0);
735
736 TEST_FREE (log);
737
738 /* Ensure no log file written */
739 TEST_LT (stat (filename, &statbuf), 0);
740
741 /* Tidy up */
742 close (pty_slave);
743
744 /************************************************************/
657 TEST_FEATURE ("ensure logger flushes when destroyed with uid 0");745 TEST_FEATURE ("ensure logger flushes when destroyed with uid 0");
658746
659 TEST_EQ (openpty (&pty_master, &pty_slave, NULL, NULL, NULL), 0);747 TEST_EQ (openpty (&pty_master, &pty_slave, NULL, NULL, NULL), 0);
@@ -1143,6 +1231,7 @@
1143 int fd;1231 int fd;
1144 NihListEntry *entry;1232 NihListEntry *entry;
1145 struct stat statbuf;1233 struct stat statbuf;
1234 char *p;
11461235
1147 TEST_FUNCTION ("log_destroy");1236 TEST_FUNCTION ("log_destroy");
11481237
@@ -1227,9 +1316,14 @@
1227 TEST_NE (fd, -1);1316 TEST_NE (fd, -1);
1228 close (fd);1317 close (fd);
12291318
1230 log = log_new (NULL, filename, pty_master, 0);1319 p = nih_strdup (NULL, "hello");
1320 TEST_NE_P (p, NULL);
1321
1322 log = log_new (p, filename, pty_master, 0);
1231 TEST_NE_P (log, NULL);1323 TEST_NE_P (log, NULL);
12321324
1325 TEST_ALLOC_PARENT (log, p);
1326
1233 ret = write (pty_slave, str, strlen (str));1327 ret = write (pty_slave, str, strlen (str));
1234 TEST_GT (ret, 0);1328 TEST_GT (ret, 0);
12351329
@@ -1244,16 +1338,26 @@
1244 log_flushed = 0;1338 log_flushed = 0;
12451339
1246 TEST_TRUE (NIH_LIST_EMPTY (log_unflushed_files));1340 TEST_TRUE (NIH_LIST_EMPTY (log_unflushed_files));
1247 ret = log_handle_unflushed (NULL, log);1341 ret = log_handle_unflushed (p, log);
1248
1249 TEST_EQ (ret, 0);1342 TEST_EQ (ret, 0);
1343
1250 TEST_FALSE (NIH_LIST_EMPTY (log_unflushed_files));1344 TEST_FALSE (NIH_LIST_EMPTY (log_unflushed_files));
12511345
1346 TEST_ALLOC_NOT_PARENT (log, p);
1347
1252 entry = (NihListEntry *)log_unflushed_files->next;1348 entry = (NihListEntry *)log_unflushed_files->next;
1253 TEST_NE_P (entry, NULL);1349 TEST_NE_P (entry, NULL);
1254 TEST_FREE_TAG (entry);1350 TEST_FREE_TAG (entry);
1255 TEST_ALLOC_PARENT (entry, log_unflushed_files);1351 TEST_ALLOC_PARENT (entry, log_unflushed_files);
12561352
1353 /* Free the original parent object and ensure it doesn't free
1354 * the log.
1355 */
1356 nih_free (p);
1357
1358 TEST_FALSE (NIH_LIST_EMPTY (log_unflushed_files));
1359 TEST_NOT_FREE (log);
1360
1257 tmp_log = entry->data;1361 tmp_log = entry->data;
1258 TEST_EQ_P (tmp_log, log);1362 TEST_EQ_P (tmp_log, log);
1259 TEST_ALLOC_PARENT (log, entry);1363 TEST_ALLOC_PARENT (log, entry);

Subscribers

People subscribed via source and target branches