Bug 1286116 - "--since-time" does not work for oc logs
Summary: "--since-time" does not work for oc logs
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: OKD
Classification: Red Hat
Component: Pod
Version: 3.x
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: ---
: ---
Assignee: Jordan Liggitt
QA Contact: Jianwei Hou
URL:
Whiteboard:
Depends On:
Blocks: 1462997
TreeView+ depends on / blocked
 
Reported: 2015-11-27 11:16 UTC by Xingxing Xia
Modified: 2020-08-13 08:20 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
: 1462997 (view as bug list)
Environment:
Last Closed: 2016-09-19 13:50:07 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Xingxing Xia 2015-11-27 11:16:52 UTC
Description of problem:
"--since-time" does not work for oc logs, it outputs error.


Version-Release number of selected component (if applicable):
openshift/oc v1.1-233-g5145e05
kubernetes v1.1.0-origin-1107-g4c8e6f4

How reproducible:
Always

Steps to Reproduce:
1. Start openshift, oc login, create a project
2. Create a pod
3. Check the log with "--since-time"
$ oc logs pod/<pod name> --since-time "2015-11-27T09:54:55.266317390Z"


Actual results:
3.
Error from server: Unable to convert <nil> to conversion.structAdaptor{typ:(*reflect.rtype)(0x2a2b080), ptr:(unsafe.Pointer)(0xc212a6f480), flag:0xd9}

Expected results:
3. The command should succeed.


Additional info:
Furthermore, it is better to directly give examples of time format in the help info rather than give RFC3339 to let customer to find it. (You can find it in http://tools.ietf.org/html/rfc3339#section-5.8)

Comment 1 Xingxing Xia 2015-12-02 06:36:57 UTC
And negative test shows strange message:
$ oc logs pod/<pod_name> --since-time="#@234"
error: parsing time "#@234" as "2006-01-02T15:04:05Z07:00": cannot parse "#@234" as "2006"

Why 'as "2006-01-02T15:04:05Z07:00"'? There must be something wrong.

Comment 2 Michail Kargakis 2015-12-02 10:17:13 UTC
This is a known issue upstream (https://github.com/kubernetes/kubernetes/issues/17561) and is actually part of a bigger problem (broken conversion from inline structs to query parameters: https://github.com/openshift/origin/pull/5396#issuecomment-151142232).

Comment 4 Xingxing Xia 2016-02-17 09:17:32 UTC
In latest versions:
openshift/oc v1.1.2-285-gb39b3d8
kubernetes v1.2.0-origin

The test result changes to:
$ oc logs pod/doublecontainers --since-time="2015-11-27T09:54:10Z"
panic: reflect: NumField of non-struct type

goroutine 1 [running]:
reflect.(*rtype).NumField(0x1a4b920, 0x1a37401)
	/usr/lib/golang/src/reflect/type.go:657 +0x7a
k8s.io/kubernetes/pkg/conversion/queryparams.convertStruct(0xc20854a630, 0x7f9085b1d0e8, 0x1a4b920, 0x1a37460, 0xc208539ee0, 0xd9)
	/go/src/github.com/openshift/origin/Godeps/_workspace/src/k8s.io/kubernetes/pkg/conversion/queryparams/convert.go:121 +0x4e
k8s.io/kubernetes/pkg/conversion/queryparams.convertStruct(0xc20854a630, 0x7f9085b1d0e8, 0x199c1a0, 0x199c1a0, 0xc20854e3c0, 0xd9)
	/go/src/github.com/openshift/origin/Godeps/_workspace/src/k8s.io/kubernetes/pkg/conversion/queryparams/convert.go:145 +0x3d1
k8s.io/kubernetes/pkg/conversion/queryparams.Convert(0x18f6a20, 0xc20854e3c0, 0x18f6a20, 0x0, 0x0)

......Much output stuff skipped......

goroutine 15 [syscall]:
os/signal.loop()
	/usr/lib/golang/src/os/signal/signal_unix.go:21 +0x1f
created by os/signal.init·1
	/usr/lib/golang/src/os/signal/signal_unix.go:27 +0x35

goroutine 35 [runnable]:
net/http.(*persistConn).readLoop(0xc2082834a0)
	/usr/lib/golang/src/net/http/transport.go:928 +0x9ce
created by net/http.(*Transport).dialConn
	/usr/lib/golang/src/net/http/transport.go:660 +0xc9f

goroutine 36 [select]:
net/http.(*persistConn).writeLoop(0xc2082834a0)
	/usr/lib/golang/src/net/http/transport.go:945 +0x41d
created by net/http.(*Transport).dialConn
	/usr/lib/golang/src/net/http/transport.go:661 +0xcbc

Comment 5 David Eads 2016-02-17 12:44:17 UTC
This pull should fix the problem, but its waiting on the current kube rebase to complete: https://github.com/openshift/origin/pull/7353.

Comment 6 Jordan Liggitt 2016-02-18 05:49:34 UTC
fix in https://github.com/openshift/origin/pull/7394

Comment 7 Xingxing Xia 2016-02-22 02:58:23 UTC
In latest version:
openshift/oc v1.1.3-170-g14b50fd
kubernetes v1.2.0-alpha.7-703-gbc4550d

Actual test result shows "--since-time" works.
Steps:
1. Start openshift, oc login, create a project
2. Create a pod (fro new app)
$ oc new-app -f origin/examples/sample-app/application-template-stibuild.json
$ oc get pod
NAME                        READY     STATUS      RESTARTS   AGE
database-1-01c97            1/1       Running     0          18m
...
3. Check the log with "--since-time"
1> $ oc logs pod/database-1-01c97 --timestamps
...
2016-02-22T02:32:59.626737885Z 160222  2:32:59  InnoDB: Starting shutdown...
2016-02-22T02:33:01.253689614Z 160222  2:33:01  InnoDB: Shutdown completed; log sequence number 1595675
...
2016-02-22T02:33:01.628302794Z ---> 02:33:01     Cleaning up environment variables MYSQL_USER, MYSQL_PASSWORD, MYSQL_DATABASE and MYSQL_ROOT_PASSWORD ...
...
2> $ oc logs pod/database-1-01c97   --timestamps --since-time="2016-02-22T02:33:01Z"
2016-02-22T02:33:01.253689614Z 160222  2:33:01  InnoDB: Shutdown completed; log sequence number 1595675
...
2016-02-22T02:33:01.628302794Z ---> 02:33:01     Cleaning up environment variables MYSQL_USER, MYSQL_PASSWORD, MYSQL_DATABASE and MYSQL_ROOT_PASSWORD ...
...

In step 3.2, it only outputs logs newer than 2016-02-22T02:33:01Z, which is we expect.

Comment 8 Xingxing Xia 2016-02-22 03:15:25 UTC
But still have 2 minor issues:
1. If using preciser time value for --since-time, the result is:
$ oc logs pod/database-1-01c97   --timestamps --since-time="2016-02-22T02:33:01.628302794Z"
It seems to ignore .628302794, and the output is:
2016-02-22T02:33:01.253689614Z 160222  2:33:01  InnoDB: Shutdown completed; log sequence number 1595675
...

This issue is very minor. Would you plan to fix this?

2. The issue in comment 1 still exists. It always mentions "2006", why "2006"?

Before move bug to VERIFIED, I'd like to know the response for the 2 issues.
Thank you.

Comment 9 Jordan Liggitt 2016-02-22 03:30:17 UTC
1. No, subsecond precision is not supported by RFC3339 (which is the format used by the API and the command-line to represent time)

2. RFC3339 is expressed in terms of an example date string:
RFC3339     = "2006-01-02T15:04:05Z07:00"
https://golang.org/pkg/time/#pkg-constants

When it attempts to parse the input text, it is doing so using that format string.

Comment 10 krupannada 2018-06-19 06:07:29 UTC
is there chance to get previous day logs for current running pods.

Comment 11 Xingxing Xia 2018-06-20 07:34:48 UTC
Use --since (relative) OR --since-time (precise time). You can add --timestamps for timestamps of each log line as well. See more in `oc logs -h`
$ oc logs --since=48h --timestamps ruby-ex-1-6rv28
PS: it does not yet support something like --until


Note You need to log in before you can comment on or make changes to this bug.