Delete CURRENT_TIME, CURRENT_TIME_SEC and current_fs_time

struct timespec is not y2038 safe on 32 bit machines and needs to be replaced by struct timespec64 in order to represent times beyond year 2038 on such machines.

Fix all the timestamp representation in struct trace_hwlat and all the corresponding implementations.

kernel/trace/trace_output.c +0 -1

index 02a4aeb..08f9bab 100644
@@ -4,7 +4,6 @@
  * Copyright (C) 2008 Red Hat Inc, Steven Rostedt <[email protected]>
  *
  */
-
 #include <linux/module.h>
 #include <linux/mutex.h>
 #include <linux/ftrace.h>

kernel/trace/trace_output.c +0 -0

 			 field->timestamp.tv_nsec);
 
 	if (field->nmi_count) {

@@ -1195,10 +1194,10 @@ trace_hwlat_raw(struct trace_iterator *iter, int flags,
 
 	trace_assign_type(field, iter->ent);

kernel/trace/trace_output.c trace_hwlat_print(struct trace_iterator *iter, int flags, · line 1167

Quoted 7 lines

kernel/trace/trace_output.c +2 -2

-     trace_seq_printf(s, "#%-5u inner/outer(us): %4llu/%-5llu ts:%ld.%09ld",
+     trace_seq_printf(s, "#%-5u inner/outer(us): %4llu/%-5llu ts:%lld.%09ld",
                       field->seqnum,
                       field->duration,
                       field->outer_duration,
-                      field->timestamp.tv_sec,
+                      (long long)field->timestamp.tv_sec,

Refresh my memory. We need the cast because on 64 bit boxes timestamp.tv_sec is just a long?

CURRENT_TIME is not y2038 safe.
The macro will be deleted and all the references to it will be replaced by ktime_get_* apis.

struct timespec is also not y2038 safe.
Retain timespec for timestamp representation here as ceph uses it internally everywhere.
These references will be changed to use struct timespec64 in a separate patch.

The current_fs_time() api is being changed to use vfs struct inode* as an argument instead of struct super_block*.

Set the new mds client request r_stamp field using ktime_get_real_ts() instead of using current_fs_time().

Also, since r_stamp is used as mtime on the server, use timespec_trunc() to truncate the timestamp, using the right granularity from the superblock.

This api will be transitioned to be y2038 safe along with vfs.

Signed-off-by Deepa Dinamani <[email protected]>

Reviewed-by Arnd Bergmann <[email protected]>

---
 drivers/block/rbd.c   | 2 +-
 fs/ceph/mds_client.c  | 4 +++-
 net/ceph/messenger.c  | 6 ++++--
 net/ceph/osd_client.c | 4 ++--
 4 files changed, 10 insertions(+), 6 deletions(-)

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

fs/ceph/mds_client.c +0 -0

        req->r_op = op;
        req->r_direct_mode = mode;

net/ceph/messenger.c +4 -2

index f76bb33..5766a6c 100644
@@ -1386,8 +1386,9 @@ static void prepare_write_keepalive(struct ceph_connection *con)
        dout("prepare_write_keepalive %p\n", con);
        con_out_kvec_reset(con);
        if (con->peer_features & CEPH_FEATURE_MSGR_KEEPALIVE2) {
-               struct timespec now = CURRENT_TIME;
+               struct timespec now;
 
+               ktime_get_real_ts(&now);
                con_out_kvec_add(con, sizeof(tag_keepalive2), &tag_keepalive2);
                ceph_encode_timespec(&con->out_temp_keepalive2, &now);
                con_out_kvec_add(con, sizeof(con->out_temp_keepalive2),

@@ -3176,8 +3177,9 @@ bool ceph_con_keepalive_expired(struct ceph_connection *con,
 {
        if (interval > 0 &&
            (con->peer_features & CEPH_FEATURE_MSGR_KEEPALIVE2)) {
-               struct timespec now = CURRENT_TIME;
+               struct timespec now;
                struct timespec ts;
+               ktime_get_real_ts(&now);
                jiffies_to_timespec(interval, &ts);
                ts = timespec_add(con->last_keepalive_ack, ts);
                return timespec_compare(&now, &ts) >= 0;

net/ceph/osd_client.c +2 -3

index e15ea9e..242d7c0 100644
@@ -3574,7 +3574,7 @@ ceph_osdc_watch(struct ceph_osd_client *osdc,
        ceph_oid_copy(&lreq->t.base_oid, oid);
        ceph_oloc_copy(&lreq->t.base_oloc, oloc);
        lreq->t.flags = CEPH_OSD_FLAG_WRITE;
-       lreq->mtime = CURRENT_TIME;
+       ktime_get_real_ts(&lreq->mtime);
 
        lreq->reg_req = alloc_linger_request(lreq);
        if (!lreq->reg_req) {

@@ -3632,7 +3632,7 @@ int ceph_osdc_unwatch(struct ceph_osd_client *osdc,
        ceph_oid_copy(&req->r_base_oid, &lreq->t.base_oid);
        ceph_oloc_copy(&req->r_base_oloc, &lreq->t.base_oloc);
        req->r_flags = CEPH_OSD_FLAG_WRITE;
-       req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&req->r_mtime);
        osd_req_op_watch_init(req, 0, lreq->linger_id,
                              CEPH_OSD_WATCH_OP_UNWATCH);
 
--

2.7.4

Quoted 29 lines · Deepa Dinamani

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

@@ -1684,7 +1685,8 @@ ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
        init_completion(&req->r_safe_completion);
        INIT_LIST_HEAD(&req->r_unsafe_item);
 

fs/ceph/mds_client.c ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode) · line 1689

Quoted 3 lines

fs/ceph/mds_client.c +2 -1

-       req->r_stamp = current_fs_time(mdsc->fsc->sb);
+       ktime_get_real_ts(&ts);
+       req->r_stamp = timespec_trunc(ts, mdsc->fsc->sb->s_time_gran);

This change causes our kernel_untar_tar test case to fail (inode's ctime goes back). The reason is that there is time drift between the time stamps got by ktime_get_real_ts() and current_time(). We need to revert this change until current_time() uses ktime_get_real_ts() internally.

Quoted 31 lines · Zheng

Quoted 29 lines · Deepa Dinamani

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

@@ -1684,7 +1685,8 @@ ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
        init_completion(&req->r_safe_completion);
        INIT_LIST_HEAD(&req->r_unsafe_item);
 

Quoted 9 lines

fs/ceph/mds_client.c ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode) · line 1689

Quoted 3 lines

fs/ceph/mds_client.c +2 -1

-       req->r_stamp = current_fs_time(mdsc->fsc->sb);
+       ktime_get_real_ts(&ts);
+       req->r_stamp = timespec_trunc(ts, mdsc->fsc->sb->s_time_gran);

This change causes our kernel_untar_tar test case to fail (inode's ctime goes back). The reason is that there is time drift between the time stamps got by ktime_get_real_ts() and current_time(). We need to revert this change until current_time() uses ktime_get_real_ts() internally.

Hmm, the change was not supposed to have a user-visible effect, so something has gone wrong, but I don't immediately see how it relates to what you observe.

ktime_get_real_ts() and current_time() use the same time base, there is no drift, but there is a difference in resolution, as the latter uses the time stamp of the last jiffies update, which may be up to one jiffy (10ms) behind the exact time we put in the request stamps here.

Do you still see problems if you use current_kernel_time() instead of ktime_get_real_ts()?

Arnd

Quoted 51 lines · Arnd Bergmann

Quoted 31 lines · Zheng

Quoted 29 lines · Deepa Dinamani

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

@@ -1684,7 +1685,8 @@ ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
        init_completion(&req->r_safe_completion);
        INIT_LIST_HEAD(&req->r_unsafe_item);
 

Quoted 9 lines

fs/ceph/mds_client.c ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode) · line 1689

Quoted 3 lines

fs/ceph/mds_client.c +2 -1

-       req->r_stamp = current_fs_time(mdsc->fsc->sb);
+       ktime_get_real_ts(&ts);
+       req->r_stamp = timespec_trunc(ts, mdsc->fsc->sb->s_time_gran);

This change causes our kernel_untar_tar test case to fail (inode's ctime goes back). The reason is that there is time drift between the time stamps got by ktime_get_real_ts() and current_time(). We need to revert this change until current_time() uses ktime_get_real_ts() internally.

Hmm, the change was not supposed to have a user-visible effect, so something has gone wrong, but I don't immediately see how it relates to what you observe.

ktime_get_real_ts() and current_time() use the same time base, there is no drift, but there is a difference in resolution, as the latter uses the time stamp of the last jiffies update, which may be up to one jiffy (10ms) behind the exact time we put in the request stamps here.

Quoted 2 lines

Do you still see problems if you use current_kernel_time() instead of ktime_get_real_ts()?

The problem disappears after using current_kernel_time().

https://github.com/ceph/ceph-client/commit/2e0f648da23167034a3cf1500bc90ec60aef2417

Quoted 52 lines · Zheng

Quoted 51 lines · Arnd Bergmann

Quoted 31 lines · Zheng

Quoted 29 lines · Deepa Dinamani

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

@@ -1684,7 +1685,8 @@ ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
        init_completion(&req->r_safe_completion);
        INIT_LIST_HEAD(&req->r_unsafe_item);
 

Quoted 9 lines

fs/ceph/mds_client.c ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode) · line 1689

Quoted 3 lines

fs/ceph/mds_client.c +2 -1

-       req->r_stamp = current_fs_time(mdsc->fsc->sb);
+       ktime_get_real_ts(&ts);
+       req->r_stamp = timespec_trunc(ts, mdsc->fsc->sb->s_time_gran);

This change causes our kernel_untar_tar test case to fail (inode's ctime goes back). The reason is that there is time drift between the time stamps got by ktime_get_real_ts() and current_time(). We need to revert this change until current_time() uses ktime_get_real_ts() internally.

Hmm, the change was not supposed to have a user-visible effect, so something has gone wrong, but I don't immediately see how it relates to what you observe.

ktime_get_real_ts() and current_time() use the same time base, there is no drift, but there is a difference in resolution, as the latter uses the time stamp of the last jiffies update, which may be up to one jiffy (10ms) behind the exact time we put in the request stamps here.

Quoted 6 lines

Quoted 2 lines

Do you still see problems if you use current_kernel_time() instead of ktime_get_real_ts()?

The problem disappears after using current_kernel_time().

https://github.com/ceph/ceph-client/commit/2e0f648da23167034a3cf1500bc90ec60aef2417

From the commit above:
"It seems there is time drift between ktime_get_real_ts() and current_kernel_time()"

Its more of a granularity difference. current_kernel_time() returns the cached time at the last tick, where as ktime_get_real_ts() reads the clocksource hardware and returns the immediate time.

Filesystems usually use the cached time (similar to CLOCK_REALTIME_COARSE), for performance reasons, as touching the clocksource takes time.

Quoted 64 lines · John Stultz

Quoted 52 lines · Zheng

Quoted 51 lines · Arnd Bergmann

Quoted 31 lines · Zheng

Quoted 29 lines · Deepa Dinamani

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

@@ -1684,7 +1685,8 @@ ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
        init_completion(&req->r_safe_completion);
        INIT_LIST_HEAD(&req->r_unsafe_item);
 

Quoted 9 lines

fs/ceph/mds_client.c ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode) · line 1689

Quoted 3 lines

fs/ceph/mds_client.c +2 -1

-       req->r_stamp = current_fs_time(mdsc->fsc->sb);
+       ktime_get_real_ts(&ts);
+       req->r_stamp = timespec_trunc(ts, mdsc->fsc->sb->s_time_gran);

This change causes our kernel_untar_tar test case to fail (inode's ctime goes back). The reason is that there is time drift between the time stamps got by ktime_get_real_ts() and current_time(). We need to revert this change until current_time() uses ktime_get_real_ts() internally.

Hmm, the change was not supposed to have a user-visible effect, so something has gone wrong, but I don't immediately see how it relates to what you observe.

ktime_get_real_ts() and current_time() use the same time base, there is no drift, but there is a difference in resolution, as the latter uses the time stamp of the last jiffies update, which may be up to one jiffy (10ms) behind the exact time we put in the request stamps here.

Quoted 6 lines

Quoted 2 lines

Do you still see problems if you use current_kernel_time() instead of ktime_get_real_ts()?

The problem disappears after using current_kernel_time().

https://github.com/ceph/ceph-client/commit/2e0f648da23167034a3cf1500bc90ec60aef2417

From the commit above:
"It seems there is time drift between ktime_get_real_ts() and current_kernel_time()"

Quoted 7 lines

Its more of a granularity difference. current_kernel_time() returns the cached time at the last tick, where as ktime_get_real_ts() reads the clocksource hardware and returns the immediate time.

Filesystems usually use the cached time (similar to CLOCK_REALTIME_COARSE), for performance reasons, as touching the clocksource takes time.

Alternatively, it would be best for this code also to use current_time(). I had suggested this in one of the previous versions of the patch. The implementation of current_time() will change when we switch vfs to use 64 bit time. This will prevent such errors from happening again. But, this also means there is more code reordering for these modules to get a reference to inode.

-Deepa

Quoted 73 lines · Deepa Dinamani

Quoted 64 lines · John Stultz

Quoted 52 lines · Zheng

Quoted 51 lines · Arnd Bergmann

Quoted 31 lines · Zheng

Quoted 29 lines · Deepa Dinamani

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

@@ -1684,7 +1685,8 @@ ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
        init_completion(&req->r_safe_completion);
        INIT_LIST_HEAD(&req->r_unsafe_item);
 

Quoted 9 lines

fs/ceph/mds_client.c ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode) · line 1689

Quoted 3 lines

fs/ceph/mds_client.c +2 -1

-       req->r_stamp = current_fs_time(mdsc->fsc->sb);
+       ktime_get_real_ts(&ts);
+       req->r_stamp = timespec_trunc(ts, mdsc->fsc->sb->s_time_gran);

This change causes our kernel_untar_tar test case to fail (inode's ctime goes back). The reason is that there is time drift between the time stamps got by ktime_get_real_ts() and current_time(). We need to revert this change until current_time() uses ktime_get_real_ts() internally.

Hmm, the change was not supposed to have a user-visible effect, so something has gone wrong, but I don't immediately see how it relates to what you observe.

ktime_get_real_ts() and current_time() use the same time base, there is no drift, but there is a difference in resolution, as the latter uses the time stamp of the last jiffies update, which may be up to one jiffy (10ms) behind the exact time we put in the request stamps here.

Quoted 6 lines

Quoted 2 lines

Do you still see problems if you use current_kernel_time() instead of ktime_get_real_ts()?

The problem disappears after using current_kernel_time().

https://github.com/ceph/ceph-client/commit/2e0f648da23167034a3cf1500bc90ec60aef2417

From the commit above:
"It seems there is time drift between ktime_get_real_ts() and current_kernel_time()"

Quoted 7 lines

Its more of a granularity difference. current_kernel_time() returns the cached time at the last tick, where as ktime_get_real_ts() reads the clocksource hardware and returns the immediate time.

Filesystems usually use the cached time (similar to CLOCK_REALTIME_COARSE), for performance reasons, as touching the clocksource takes time.

Quoted 7 lines

Alternatively, it would be best for this code also to use current_time(). I had suggested this in one of the previous versions of the patch. The implementation of current_time() will change when we switch vfs to use 64 bit time. This will prevent such errors from happening again. But, this also means there is more code reordering for these modules to get a reference to inode.

I took a look. it's quite inconvenience to use current_time(). I prefer to temporarily use current_kernel_time().

Quoted 82 lines · Zheng

Quoted 73 lines · Deepa Dinamani

Quoted 64 lines · John Stultz

Quoted 52 lines · Zheng

Quoted 51 lines · Arnd Bergmann

Quoted 31 lines · Zheng

Quoted 29 lines · Deepa Dinamani

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

@@ -1684,7 +1685,8 @@ ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
        init_completion(&req->r_safe_completion);
        INIT_LIST_HEAD(&req->r_unsafe_item);
 

Quoted 9 lines

fs/ceph/mds_client.c ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode) · line 1689

Quoted 3 lines

fs/ceph/mds_client.c +2 -1

-       req->r_stamp = current_fs_time(mdsc->fsc->sb);
+       ktime_get_real_ts(&ts);
+       req->r_stamp = timespec_trunc(ts, mdsc->fsc->sb->s_time_gran);

This change causes our kernel_untar_tar test case to fail (inode's ctime goes back). The reason is that there is time drift between the time stamps got by ktime_get_real_ts() and current_time(). We need to revert this change until current_time() uses ktime_get_real_ts() internally.

Hmm, the change was not supposed to have a user-visible effect, so something has gone wrong, but I don't immediately see how it relates to what you observe.

ktime_get_real_ts() and current_time() use the same time base, there is no drift, but there is a difference in resolution, as the latter uses the time stamp of the last jiffies update, which may be up to one jiffy (10ms) behind the exact time we put in the request stamps here.

Quoted 6 lines

Quoted 2 lines

Do you still see problems if you use current_kernel_time() instead of ktime_get_real_ts()?

The problem disappears after using current_kernel_time().

https://github.com/ceph/ceph-client/commit/2e0f648da23167034a3cf1500bc90ec60aef2417

From the commit above:
"It seems there is time drift between ktime_get_real_ts() and current_kernel_time()"

Quoted 7 lines

Its more of a granularity difference. current_kernel_time() returns the cached time at the last tick, where as ktime_get_real_ts() reads the clocksource hardware and returns the immediate time.

Filesystems usually use the cached time (similar to CLOCK_REALTIME_COARSE), for performance reasons, as touching the clocksource takes time.

Quoted 7 lines

Alternatively, it would be best for this code also to use current_time(). I had suggested this in one of the previous versions of the patch. The implementation of current_time() will change when we switch vfs to use 64 bit time. This will prevent such errors from happening again. But, this also means there is more code reordering for these modules to get a reference to inode.

Quoted 2 lines

I took a look. it's quite inconvenience to use current_time(). I prefer to temporarily use current_kernel_time().

I've looked at the code some more and I think there is another angle to it:
In your test case, 'tar' calls into the utimes syscall (or a member of its family), which sets the i_ctime field in the inode to the curren time (using current_time()), then calls __ceph_setattr(), which creates a mds client request, and ceph_mdsc_create_request() takes another time stamp and stores it in r_stamp.

We then store the first timestamp (only) in the in-memory inode, and the second time stamp in the request. Depending on the state of the inode, we may also set the ctime to a third timestamp we again take using current_time().

The mtime and atime from user space get passed correctly through union ceph_mds_request_args->setattr and are kept in sync between the in-memory inode and the persistent inode data, but the ctime in the inode never makes it to the lower protocol levels and instead we use the r_stamp field that got set a little earlier or a little later.

I believe the bug you see is the result of the two timestamps currently being almost guaranteed to be different in the latest kernels.
Changing r_stamp to use current_kernel_time() will make it the same value most of the time (as it was before Deepa's patch), but when the timer interrupt happens between the timestamps, the two are still different, it's just much harder to hit.

I think the proper solution should be to change __ceph_setattr() in a way that has req->r_stamp always synchronized with i_ctime. If we copy i_ctime to r_stamp, that will also take care of the future issues with the planned changes to current_time().

The part I don't understand is what else r_stamp (i.e. the time stamp in ceph_msg_data with type== CEPH_MSG_CLIENT_REQUEST) is used for, other than setting ctime in CEPH_MDS_OP_SETATTR.

Will this be used to update the stored i_ctime for other operations too? If so, we would need to synchronize it with the in-memory i_ctime for all operations that do this.

Semi-related side note: I see that the granularity for ceph_timespec is 1000 nanoseconds, so the value is always a multiple of 1000. If the full 32-bit data gets stored, we could use this it to store the epoch number in the future:

static inline void ceph_decode_timespec(struct timespec64 *ts,
const struct ceph_timespec *tv)

{
        u32 ns_epoch = le32_to_cpu(tv->tv_nsec);
        u32 epoch = ns_epoch % 1000;

        /* tv_sec is traditionally interpreted as unsigned
         * with time ranges 1970-2106, we extend
         * it to 1970-138069 */
        ts->tv_sec = (u64)le32_to_cpu(tv->tv_sec) +
                            (u64)epoch << 32;
        ts->tv_nsec = ns_epoch - epoch;
}

Arnd

Quoted 13 lines · Arnd Bergmann

Quoted 3 lines · Zheng

Quoted 2 lines · Deepa Dinamani

Quoted 1 line · John Stultz

On Thu, Jun 1, 2017 at 5:26 PM, Yan, Zheng <[email protected]> wrote:

I believe the bug you see is the result of the two timestamps currently being almost guaranteed to be different in the latest kernels.
Changing r_stamp to use current_kernel_time() will make it the same value most of the time (as it was before Deepa's patch), but when the timer interrupt happens between the timestamps, the two are still different, it's just much harder to hit.

Quoted 5 lines

I think the proper solution should be to change __ceph_setattr() in a way that has req->r_stamp always synchronized with i_ctime. If we copy i_ctime to r_stamp, that will also take care of the future issues with the planned changes to current_time().

I already have a patch
https://github.com/ceph/ceph-client/commit/24f54cd18e195a002ee3d2ab50dbc952fd9f82af

Quoted 5 lines

The part I don't understand is what else r_stamp (i.e. the time stamp in ceph_msg_data with type== CEPH_MSG_CLIENT_REQUEST) is used for, other than setting ctime in CEPH_MDS_OP_SETATTR.

Quoted 4 lines

Will this be used to update the stored i_ctime for other operations too? If so, we would need to synchronize it with the in-memory i_ctime for all operations that do this.

yes, mds uses it to update ctime of modified inodes. For example, when handling mkdir, mds set ctime of both parent inode and new inode to r_stamp.

Quoted 14 lines · Zheng

Quoted 13 lines · Arnd Bergmann

Quoted 3 lines · Zheng

Quoted 2 lines · Deepa Dinamani

Quoted 1 line · John Stultz

On Thu, Jun 1, 2017 at 5:26 PM, Yan, Zheng <[email protected]> wrote:

I believe the bug you see is the result of the two timestamps currently being almost guaranteed to be different in the latest kernels.
Changing r_stamp to use current_kernel_time() will make it the same value most of the time (as it was before Deepa's patch), but when the timer interrupt happens between the timestamps, the two are still different, it's just much harder to hit.

Quoted 7 lines

Quoted 5 lines

I think the proper solution should be to change __ceph_setattr() in a way that has req->r_stamp always synchronized with i_ctime. If we copy i_ctime to r_stamp, that will also take care of the future issues with the planned changes to current_time().

I already have a patch
https://github.com/ceph/ceph-client/commit/24f54cd18e195a002ee3d2ab50dbc952fd9f82af

Looks good to me. In case anyone cares:

Acked-by Arnd Bergmann <[email protected]>

Quoted 5 lines

Quoted 5 lines

The part I don't understand is what else r_stamp (i.e. the time stamp in ceph_msg_data with type== CEPH_MSG_CLIENT_REQUEST) is used for, other than setting ctime in CEPH_MDS_OP_SETATTR.

Quoted 8 lines

Quoted 4 lines

Will this be used to update the stored i_ctime for other operations too? If so, we would need to synchronize it with the in-memory i_ctime for all operations that do this.

yes, mds uses it to update ctime of modified inodes. For example, when handling mkdir, mds set ctime of both parent inode and new inode to r_stamp.

I see, so we may have a variation of that problem there as well: From my reading of the code, the child inode is not in memory yet, so that seems fine, but I could not find where the parent in-memory inode i_ctime is updated in ceph, but it is most likely not the same as req->r_stamp (assuming it gets updated at all).

Would it make sense require all callers of ceph_mdsc_do_request() to update r_stamp at the same time as i_ctime to keep them in sync?

Arnd

Quoted 40 lines · Arnd Bergmann

Quoted 14 lines · Zheng

Quoted 13 lines · Arnd Bergmann

Quoted 3 lines · Zheng

Quoted 2 lines · Deepa Dinamani

Quoted 1 line · John Stultz

On Thu, Jun 1, 2017 at 5:26 PM, Yan, Zheng <[email protected]> wrote:

I believe the bug you see is the result of the two timestamps currently being almost guaranteed to be different in the latest kernels.
Changing r_stamp to use current_kernel_time() will make it the same value most of the time (as it was before Deepa's patch), but when the timer interrupt happens between the timestamps, the two are still different, it's just much harder to hit.

Quoted 7 lines

Quoted 5 lines

I think the proper solution should be to change __ceph_setattr() in a way that has req->r_stamp always synchronized with i_ctime. If we copy i_ctime to r_stamp, that will also take care of the future issues with the planned changes to current_time().

I already have a patch
https://github.com/ceph/ceph-client/commit/24f54cd18e195a002ee3d2ab50dbc952fd9f82af

Looks good to me. In case anyone cares:

Acked-by Arnd Bergmann <[email protected]>

Quoted 5 lines

Quoted 5 lines

The part I don't understand is what else r_stamp (i.e. the time stamp in ceph_msg_data with type== CEPH_MSG_CLIENT_REQUEST) is used for, other than setting ctime in CEPH_MDS_OP_SETATTR.

Quoted 8 lines

Quoted 4 lines

Will this be used to update the stored i_ctime for other operations too? If so, we would need to synchronize it with the in-memory i_ctime for all operations that do this.

yes, mds uses it to update ctime of modified inodes. For example, when handling mkdir, mds set ctime of both parent inode and new inode to r_stamp.

Quoted 5 lines

I see, so we may have a variation of that problem there as well: From my reading of the code, the child inode is not in memory yet, so that seems fine, but I could not find where the parent in-memory inode i_ctime is updated in ceph, but it is most likely not the same as req->r_stamp (assuming it gets updated at all).

i_ctime is updated when handling request reply, by ceph_fill_file_time(). __ceph_setattr() can update the in-memory inode's ctime after request reply is received. The difference between ktime_get_real_ts() and current_time() can be larger than round-trip time of request. So it's still possible that __ceph_setattr() make ctime go back.

Quoted 2 lines

Would it make sense require all callers of ceph_mdsc_do_request() to update r_stamp at the same time as i_ctime to keep them in sync?

Quoted 47 lines · Zheng

Quoted 40 lines · Arnd Bergmann

Quoted 14 lines · Zheng

Quoted 13 lines · Arnd Bergmann

Quoted 3 lines · Zheng

Quoted 2 lines · Deepa Dinamani

Quoted 1 line · John Stultz

On Thu, Jun 1, 2017 at 5:26 PM, Yan, Zheng <[email protected]> wrote:

I believe the bug you see is the result of the two timestamps currently being almost guaranteed to be different in the latest kernels.
Changing r_stamp to use current_kernel_time() will make it the same value most of the time (as it was before Deepa's patch), but when the timer interrupt happens between the timestamps, the two are still different, it's just much harder to hit.

Quoted 7 lines

Quoted 5 lines

I think the proper solution should be to change __ceph_setattr() in a way that has req->r_stamp always synchronized with i_ctime. If we copy i_ctime to r_stamp, that will also take care of the future issues with the planned changes to current_time().

I already have a patch
https://github.com/ceph/ceph-client/commit/24f54cd18e195a002ee3d2ab50dbc952fd9f82af

Looks good to me. In case anyone cares:

Acked-by Arnd Bergmann <[email protected]>

Quoted 5 lines

Quoted 5 lines

The part I don't understand is what else r_stamp (i.e. the time stamp in ceph_msg_data with type== CEPH_MSG_CLIENT_REQUEST) is used for, other than setting ctime in CEPH_MDS_OP_SETATTR.

Quoted 8 lines

Quoted 4 lines

Will this be used to update the stored i_ctime for other operations too? If so, we would need to synchronize it with the in-memory i_ctime for all operations that do this.

yes, mds uses it to update ctime of modified inodes. For example, when handling mkdir, mds set ctime of both parent inode and new inode to r_stamp.

Quoted 5 lines

I see, so we may have a variation of that problem there as well: From my reading of the code, the child inode is not in memory yet, so that seems fine, but I could not find where the parent in-memory inode i_ctime is updated in ceph, but it is most likely not the same as req->r_stamp (assuming it gets updated at all).

Quoted 5 lines

i_ctime is updated when handling request reply, by ceph_fill_file_time(). __ceph_setattr() can update the in-memory inode's ctime after request reply is received. The difference between ktime_get_real_ts() and current_time() can be larger than round-trip time of request. So it's still possible that __ceph_setattr() make ctime go back.

But the __ceph_setattr() problem should be fixed by your patch, right?

What I meant is another related problem in ceph_mkdir() where the i_ctime field of the parent inode is different between the persistent representation in the mds and the in-memory representation.

Arnd

Quoted 2 lines

Quoted 2 lines

Would it make sense require all callers of ceph_mdsc_do_request() to update r_stamp at the same time as i_ctime to keep them in sync?

Quoted 5 lines · Arnd Bergmann

On Fri, Jun 2, 2017 at 1:18 PM, Yan, Zheng <[email protected]> wrote:
What I meant is another related problem in ceph_mkdir() where the
i_ctime field of the parent inode is different between the persistent representation in the mds and the in-memory representation.

I don't see any problem in mkdir case. Parent inode's i_ctime in mds is set to r_stamp. When client receives request reply, it set its in-memory inode's ctime to the same time stamp.

Quoted 10 lines · Zheng

Quoted 5 lines · Arnd Bergmann

On Fri, Jun 2, 2017 at 1:18 PM, Yan, Zheng <[email protected]> wrote:
What I meant is another related problem in ceph_mkdir() where the i_ctime field of the parent inode is different between the persistent representation in the mds and the in-memory representation.

I don't see any problem in mkdir case. Parent inode's i_ctime in mds is set to r_stamp. When client receives request reply, it set its in-memory inode's ctime to the same time stamp.

Ok, I see it now, thanks for the clarification. Most other file systems do this the other way round and update all fields in the in-memory inode structure first and then write that to persistent storage, so I was getting confused about the order of events here.

If I understand it all right, we have three different behaviors in ceph now, though the differences are very minor and probably don't ever matter:

- in setattr(), we update ctime in the in-memory inode first and then send the same time to the mds, and expect to set it again when the reply comes.

- in ceph_write_iter write() and mmap/page_mkwrite(), we call file_update_time() to set i_mtime and i_ctime to the same timestamp first once a write is observed by the fs and then take two other timestamps that we send to the mds, and update the in-memory inode a second time when the reply comes. ctime is never older than mtime here, as far as I can tell, but it may be newer when the timer interrupt happens between taking the two stamps.

- in all other calls, we only update the inode (and/or parent inode) after the reply arrives.

Arnd

Quoted 31 lines · Zheng

Quoted 29 lines · Deepa Dinamani

drivers/block/rbd.c +1 -1

index 517838b..77204da 100644
@@ -1922,7 +1922,7 @@ static void rbd_osd_req_format_write(struct rbd_obj_request *obj_request)
 {
        struct ceph_osd_request *osd_req = obj_request->osd_req;
 
-       osd_req->r_mtime = CURRENT_TIME;
+       ktime_get_real_ts(&osd_req->r_mtime);
        osd_req->r_data_offset = obj_request->offset;
 }
 

fs/ceph/mds_client.c +1 -0

index c681762..1d3fa90 100644
@@ -1666,6 +1666,7 @@ struct ceph_mds_request *
 ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
 {
        struct ceph_mds_request *req = kzalloc(sizeof(*req), GFP_NOFS);
+       struct timespec ts;
 
        if (!req)
                return ERR_PTR(-ENOMEM);

@@ -1684,7 +1685,8 @@ ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode)
        init_completion(&req->r_safe_completion);
        INIT_LIST_HEAD(&req->r_unsafe_item);
 

Quoted 9 lines

fs/ceph/mds_client.c ceph_mdsc_create_request(struct ceph_mds_client *mdsc, int op, int mode) · line 1689

Quoted 3 lines

fs/ceph/mds_client.c +2 -1

-       req->r_stamp = current_fs_time(mdsc->fsc->sb);
+       ktime_get_real_ts(&ts);
+       req->r_stamp = timespec_trunc(ts, mdsc->fsc->sb->s_time_gran);

This change causes our kernel_untar_tar test case to fail (inode's ctime goes back). The reason is that there is time drift between the time stamps got by ktime_get_real_ts() and current_time(). We need to revert this change until current_time() uses ktime_get_real_ts() internally.

Hmm, the change was not supposed to have a user-visible effect, so something has gone wrong, but I don't immediately see how it relates to what you observe.

ktime_get_real_ts() and current_time() use the same time base, there is no drift, but there is a difference in resolution, as the latter uses the time stamp of the last jiffies update, which may be up to one jiffy (10ms) behind the exact time we put in the request stamps here.

Do you still see problems if you use current_kernel_time() instead of ktime_get_real_ts()?

Arnd

struct timespec is not y2038 safe.
Audit timestamps are recorded in string format into an audit buffer for a given context.
These mark the entry timestamps for the syscalls. Use y2038 safe struct timespec64 to represent the times. The log strings can handle this transition as strings can hold upto 1024 characters.

Signed-off-by Deepa Dinamani <[email protected]>

Reviewed-by Arnd Bergmann <[email protected]>

Acked-by Paul Moore <[email protected]>

Acked-by Richard Guy Briggs <[email protected]>

---
 include/linux/audit.h |  4 ++--
 kernel/audit.c        | 10 +++++-----
 kernel/audit.h        |  2 +-
 kernel/auditsc.c      |  6 +++---
 4 files changed, 11 insertions(+), 11 deletions(-)

include/linux/audit.h +2 -2

index 6fdfefc..f830508 100644
@@ -332,7 +332,7 @@ static inline void audit_ptrace(struct task_struct *t)
                                /* Private API (for audit.c only) */
 extern unsigned int audit_serial(void);
 extern int auditsc_get_stamp(struct audit_context *ctx,
-                             struct timespec *t, unsigned int *serial);
+                             struct timespec64 *t, unsigned int *serial);
 extern int audit_set_loginuid(kuid_t loginuid);
 
 static inline kuid_t audit_get_loginuid(struct task_struct *tsk)

@@ -511,7 +511,7 @@ static inline void __audit_seccomp(unsigned long syscall, long signr, int code)
 static inline void audit_seccomp(unsigned long syscall, long signr, int code)
 { }
 static inline int auditsc_get_stamp(struct audit_context *ctx,
-                             struct timespec *t, unsigned int *serial)
+                             struct timespec64 *t, unsigned int *serial)
 {
        return 0;
 }

kernel/audit.c +5 -5

index 2f4964c..fcbf377 100644
@@ -1625,10 +1625,10 @@ unsigned int audit_serial(void)
 }
 
 static inline void audit_get_stamp(struct audit_context *ctx,
-                                  struct timespec *t, unsigned int *serial)
+                                  struct timespec64 *t, unsigned int *serial)
 {
        if (!ctx || !auditsc_get_stamp(ctx, t, serial)) {
-               *t = CURRENT_TIME;
+               ktime_get_real_ts64(t);
                *serial = audit_serial();
        }
 }

@@ -1652,7 +1652,7 @@ struct audit_buffer *audit_log_start(struct audit_context *ctx, gfp_t gfp_mask,
                                     int type)
 {
        struct audit_buffer *ab;
-       struct timespec t;
+       struct timespec64 t;
        unsigned int uninitialized_var(serial);
 
        if (audit_initialized != AUDIT_INITIALIZED)

@@ -1705,8 +1705,8 @@ struct audit_buffer *audit_log_start(struct audit_context *ctx, gfp_t gfp_mask,
        }
 
        audit_get_stamp(ab->ctx, &t, &serial);
-       audit_log_format(ab, "audit(%lu.%03lu:%u): ",
-                        t.tv_sec, t.tv_nsec/1000000, serial);
+       audit_log_format(ab, "audit(%llu.%03lu:%u): ",
+                        (unsigned long long)t.tv_sec, t.tv_nsec/1000000, serial);
 
        return ab;
 }

kernel/audit.h +1 -1

index 0f1cf6d..cdf96f4 100644
@@ -112,7 +112,7 @@ struct audit_context {
        enum audit_state    state, current_state;
        unsigned int        serial;     /* serial number for record */
        int                 major;      /* syscall number */
-       struct timespec     ctime;      /* time of syscall entry */
+       struct timespec64   ctime;      /* time of syscall entry */
        unsigned long       argv[4];    /* syscall arguments */
        long                return_code;/* syscall return code */
        u64                 prio;

kernel/auditsc.c +3 -4

index e59ffc7..a2d9217 100644
@@ -1532,7 +1532,7 @@ void __audit_syscall_entry(int major, unsigned long a1, unsigned long a2,
                return;
 
        context->serial     = 0;
-       context->ctime      = CURRENT_TIME;
+       ktime_get_real_ts64(&context->ctime);
        context->in_syscall = 1;
        context->current_state  = state;
        context->ppid       = 0;

@@ -1941,13 +1941,13 @@ EXPORT_SYMBOL_GPL(__audit_inode_child);
 /**
  * auditsc_get_stamp - get local copies of audit_context values
  * @ctx: audit_context for the task
- * @t: timespec to store time recorded in the audit_context
+ * @t: timespec64 to store time recorded in the audit_context
  * @serial: serial value that is recorded in the audit_context
  *
  * Also sets the context as auditable.
  */
 int auditsc_get_stamp(struct audit_context *ctx,
-                      struct timespec *t, unsigned int *serial)
+                      struct timespec64 *t, unsigned int *serial)
 {
        if (!ctx->in_syscall)
                return 0;
--

2.7.4

I have no problem merging this patch into audit/next for v4.12, would you prefer me to do that so at least this patch is merged?

It would probably make life a small bit easier for us in the audit world too as it would reduce the potential merge conflict. However, that's a relatively small thing to worry about.

Quoted 2 lines

I have no problem merging this patch into audit/next for v4.12, would you prefer me to do that so at least this patch is merged?

This would be fine.
But, I think whoever takes the last 2 deletion patches should also take them. I'm not sure how that part works out.

Quoted 3 lines

It would probably make life a small bit easier for us in the audit world too as it would reduce the potential merge conflict. However, that's a relatively small thing to worry about.

Quoted 2 lines

I have no problem merging this patch into audit/next for v4.12, would you prefer me to do that so at least this patch is merged?

This would be fine.
But, I think whoever takes the last 2 deletion patches should also take them. I'm not sure how that part works out.

Quoted 3 lines

It would probably make life a small bit easier for us in the audit world too as it would reduce the potential merge conflict. However, that's a relatively small thing to worry about.

btrfs_root_item maintains the ctime for root updates. This is not part of vfs_inode.

Since current_time() uses struct inode* as an argument as Linus suggested, this cannot be used to update root times unless, we modify the signature to use inode.

Since btrfs uses nanosecond time granularity, it can also use ktime_get_real_ts directly to obtain timestamp for the root. It is necessary to use the timespec time api here because the same btrfs_set_stack_timespec_*() apis are used for vfs inode times as well. These can be transitioned to using timespec64 when btrfs internally changes to use timespec64 as well.

Signed-off-by Deepa Dinamani <[email protected]>

Acked-by David Sterba <[email protected]>

Reviewed-by Arnd Bergmann <[email protected]>

CURRENT_TIME macro is not y2038 safe on 32 bit systems.

The patch replaces all the uses of CURRENT_TIME by current_time().

This is also in preparation for the patch that transitions vfs timestamps to use 64 bit time and hence make them y2038 safe. current_time() is also planned to be transitioned to y2038 safe behavior along with this change.

CURRENT_TIME macro will be deleted before merging the aforementioned change.

Signed-off-by Deepa Dinamani <[email protected]>

---
 security/apparmor/apparmorfs.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

security/apparmor/apparmorfs.c +0 -0

index be0b498..4f6ac9d 100644