Fix event ordering

The ordering of events, whether by events, node log, hook log, or commands,
previously showed events in counter-intuitive order. This puts the latest
entry at the bottom, which should be most useful.

Additionally, whenever a limited "fact" collection is requested, it will
limit from the bottom up. This means `razor events --limit 5` will show the 5
most recent events, with the most recent at the bottom.

Fixes https://tickets.puppetlabs.com/browse/RAZOR-734

app.rb

@@ -559,7 +559,8 @@ def render_template(name)
   # @todo danielp 2013-06-26: this should be some sort of discovery, not a
   # hand-coded list, but ... it will do, for now.
   COLLECTIONS = [:brokers, :repos, :tags, :policies,
-                 [:nodes, {'start' => {"type" => "number"}, 'limit' => {"type" => "number"}}], :tasks, :commands,
+                 [:nodes, {'start' => {"type" => "number"}, 'limit' => {"type" => "number"}}],
+                  :tasks, :commands,
                  [:events, {'start' => {"type" => "number"}, 'limit' => {"type" => "number"}}], :hooks]
 
   #
@@ -613,6 +614,16 @@ def render_template(name)
     check_permissions!("query:#{collection}" + (item ? ":#{item}" : ''))
   end
 
+  def paginate(start, limit)
+    raise TypeError, _('limit must be a number, but was %{limit}') %
+        {limit: limit} unless limit.to_i.to_s == limit or limit.nil?
+    raise TypeError, _('start must be a number, but was %{start}') %
+        {start: start} unless start.to_i.to_s == start or start.nil?
+    limit = Integer(limit) if limit
+    start = Integer(start) if start
+    [start, limit]
+  end
+
   get '/api/collections/tags' do
     collection_view Razor::Data::Tag, "tags"
   end
@@ -692,8 +703,8 @@ def render_template(name)
   end
 
   get '/api/collections/commands' do
-    collection_view Razor::Data::Command.order(:submitted_at).reverse,
-      'commands'
+    collection_view Razor::Data::Command.order(:submitted_at).order(:id),
+      'commands', limit: limit, start: start, facts: true
   end
 
   get '/api/collections/commands/:id' do
@@ -708,47 +719,50 @@ def render_template(name)
   end
 
   get '/api/collections/events' do
-    check_permissions!("query:events")
+    start, limit = paginate(params[:start], params[:limit])
 
     # Need to also order by ID here in case the granularity of timestamp is
     # not enough to maintain a consistent ordering.
-    cursor = Razor::Data::Event.order(:timestamp).order(:id).reverse
-    collection_view cursor, 'events', limit: params[:limit], start: params[:start]
+    cursor = Razor::Data::Event.order(:timestamp).order(:id)
+    collection_view cursor, 'events', limit: limit, start: start, facts: true
   end
 
   get '/api/collections/events/:id' do
     params[:id] =~ /[0-9]+/ or error 400, :error => _("id must be a number but was %{id}") % {id: params[:id]}
-    check_permissions!("query:events:#{params[:id]}")
+
     event = Razor::Data::Event[:id => params[:id]] or
         error 404, :error => _("no event matched id=%{id}") % {id: params[:id]}
     event_hash(event).to_json
   end
 
   get '/api/collections/hooks' do
-    check_permissions!("query:hooks")
-
     collection_view Razor::Data::Hook, 'hooks'
   end
 
   get '/api/collections/hooks/:name' do
-    check_permissions!("query:hooks:#{params[:name]}")
     hook = Razor::Data::Hook[:name => params[:name]] or
         error 404, :error => _("no hook matched name=%{name}") % {name: params[:name]}
     hook_hash(hook).to_json
   end
 
   get '/api/collections/hooks/:name/log' do
-    check_permissions!("query:hooks:#{params[:name]}")
+    check_permissions!("query:hooks:#{params[:name]}:log")
+
+    start, limit = paginate(params[:start], params[:limit])
+
     hook = Razor::Data::Hook[:name => params[:name]] or
         error 404, :error => _("no hook matched name=%{name}") % {name: params[:name]}
     {
         "spec" => spec_url("collections", "hooks", "log"),
-        "items" => hook.log(limit: params[:limit], start: params[:start])
+        "items" => hook.log(limit: limit, start: start)
     }.to_json
   end
 
   get '/api/collections/nodes' do
-    collection_view Razor::Data::Node.search(params).order(:id), 'nodes', limit: params[:limit], start: params[:start]
+    start, limit = paginate(params[:start], params[:limit])
+
+    collection_view Razor::Data::Node.search(params).order(:id), 'nodes',
+                    limit: limit, start: start
   end
 
   get '/api/collections/nodes/:name' do
@@ -760,6 +774,8 @@ def render_template(name)
   get '/api/collections/nodes/:name/log' do
     check_permissions!("query:nodes:#{params[:name]}:log")
 
+    start, limit = paginate(params[:start], params[:limit])
+
     # @todo lutter 2013-08-20: There are no tests for this handler
     # @todo lutter 2013-08-20: Do we need to send the log through a view ?
     node = Razor::Data::Node[:name => params[:name]] or
@@ -769,7 +785,7 @@ def render_template(name)
     # view worthwhile without extra querying.
     {
       "spec" => spec_url("collections", "nodes", "log"),
-      "items" => node.log(limit: params[:limit], start: params[:start])
+      "items" => node.log(limit: limit, start: start)
     }.to_json
   end
 

lib/razor/data/hook.rb

@@ -149,8 +149,15 @@ def validate
   end
 
   def log(params = {})
-    cursor = Razor::Data::Event.order(:timestamp).order(:id).reverse.
-        where(hook_id: id).limit(params[:limit], params[:start])
+    cursor = Razor::Data::Event.order(:timestamp).order(:id).
+        where(hook_id: id)
+    total = cursor.count if cursor.respond_to?(:count)
+    if params[:start].nil? and params[:limit] and !total.nil?
+      # We have a request for a limited list of facts without a starting
+      # value. Take from the end so the latest entries are included.
+      params[:start] = [total - params[:limit], 0].max
+    end
+    cursor = cursor.limit(params[:limit], params[:start])
     cursor.map do |log|
       { 'timestamp' => log.timestamp.xmlschema, 'node' => (log.node ? log.node.name : nil),
         'policy' => (log.policy ? log.policy.name : nil)}.update(log.entry).delete_if { |_,v| v.nil? }

lib/razor/data/node.rb

@@ -136,8 +136,15 @@ def shortname
     # +log_append+ each entry will also contain the +timestamp+ in ISO8601
     # format
     def log(params = {})
-      cursor = Razor::Data::Event.order(:timestamp).order(:id).reverse.
-          where(node_id: id).limit(params[:limit], params[:start])
+      cursor = Razor::Data::Event.order(:timestamp).order(:id).
+          where(node_id: id)
+      total = cursor.count if cursor.respond_to?(:count)
+      if params[:start].nil? and params[:limit] and !total.nil?
+        # We have a request for a limited list of facts without a starting
+        # value. Take from the end so the latest entries are included.
+        params[:start] = [total - params[:limit], 0].max
+      end
+      cursor = cursor.limit(params[:limit], params[:start])
       cursor.map do |log|
         { 'timestamp' => log.timestamp.xmlschema,
           'severity' => log.severity, }.update(log.entry)

lib/razor/view.rb

@@ -216,6 +216,11 @@ def hook_hash(hook)
     def collection_view(cursor, name, args = {})
       perm = "query:#{name}"
       total = cursor.count if cursor.respond_to?(:count)
+      if args[:facts] and args[:start].nil? and args[:limit] and !total.nil?
+        # We have a request for a limited list of facts without a starting
+        # value. Take from the end so the latest entries are included.
+        args[:start] = [total - args[:limit], 0].max
+      end
       # This catches the case where a non-Sequel class is passed in.
       cursor = cursor.all if cursor.is_a?(Class) and !cursor.respond_to?(:cursor)
       cursor = cursor.limit(args[:limit], args[:start]) if cursor.respond_to?(:limit)

spec/app/api_spec.rb

@@ -848,7 +848,7 @@ def validate!(schema, json)
     let :node do Fabricate(:node) end
     let :msgs do [] end
     before :each do
-      5.times { msgs.unshift(Fabricate(:event, node: node).entry[:msg]) }
+      5.times { msgs.push(Fabricate(:event, node: node).entry[:msg]) }
     end
     it "should show log" do
       get "/api/collections/nodes/#{node.name}/log"
@@ -860,7 +860,7 @@ def validate!(schema, json)
       get "/api/collections/nodes/#{node.name}/log?limit=2"
       last_response.status.should == 200
 
-      last_response.json['items'].map {|e| e['msg']}.should == msgs[0..1]
+      last_response.json['items'].map {|e| e['msg']}.should == msgs[3..4]
     end
     it "should show limited log with offset" do
       get "/api/collections/nodes/#{node.name}/log?limit=2&start=2"
@@ -1115,7 +1115,7 @@ def validate!(schema, json)
     let :hook do Fabricate(:hook) end
     let :msgs do [] end
     before :each do
-      5.times { msgs.unshift(Fabricate(:event, hook: hook).entry[:msg]) }
+      5.times { msgs.push(Fabricate(:event, hook: hook).entry[:msg]) }
     end
     it "should show log" do
       get "/api/collections/hooks/#{URI.escape(hook.name)}/log"
@@ -1127,7 +1127,7 @@ def validate!(schema, json)
       get "/api/collections/hooks/#{URI.escape(hook.name)}/log?limit=2"
       last_response.status.should == 200
 
-      last_response.json['items'].map {|e| e['msg']}.should == msgs[0..1]
+      last_response.json['items'].map {|e| e['msg']}.should == msgs[3..4]
     end
     it "should show limited log with offset" do
       get "/api/collections/hooks/#{URI.escape(hook.name)}/log?limit=2&start=2"
@@ -1280,13 +1280,13 @@ def validate!(schema, json)
         events = last_response.json['items']
         events.should be_an_instance_of Array
         events.count.should == 1
-        events.first['name'].should == names.last
+        events.last['name'].should == names.last
         last_response.json['total'].should == 3
         validate! ObjectRefCollectionSchema, last_response.body
       end
       it "should allow windowing of results" do
         names = []
-        6.times { names.unshift Fabricate(:event).name }
+        6.times { names.push Fabricate(:event).name }
         get "/api/collections/events?limit=2&start=2"
 
         last_response.status.should == 200
@@ -1299,7 +1299,7 @@ def validate!(schema, json)
       end
       it "should allow just an offset" do
         names = []
-        6.times { names.unshift Fabricate(:event).name }
+        6.times { names.push Fabricate(:event).name }
         get "/api/collections/events?start=2"
 
         last_response.status.should == 200

spec/data/node_spec.rb

@@ -219,12 +219,12 @@ def canonicalize(hw_info)
 
     n = Node[node.id]
     n.log.size.should == 2
-    n.log[0]["msg"].should == "M2"
-    n.log[0]["severity"].should == "error"
-    n.log[0]["timestamp"].should_not be_nil
-    n.log[1]["msg"].should == "M1"
-    n.log[1]["severity"].should == "info"
+    n.log[1]["msg"].should == "M2"
+    n.log[1]["severity"].should == "error"
     n.log[1]["timestamp"].should_not be_nil
+    n.log[0]["msg"].should == "M1"
+    n.log[0]["severity"].should == "info"
+    n.log[0]["timestamp"].should_not be_nil
   end
 
   describe "hostname" do
@@ -295,8 +295,8 @@ def canonicalize(hw_info)
       node.modified?.should be_false
 
       node.policy.should == policy
-      node.log.first["action"].should == "reboot"
-      node.log.first["policy"].should == policy.name
+      node.log.last["action"].should == "reboot"
+      node.log.last["policy"].should == policy.name
     end
 
     it "should refuse to bind to a policy if any tag raises an error" do