Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

logging initializer and gtfs_graph log function #615

Merged
merged 2 commits into from
Jun 9, 2016
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions app/models/stop.rb
Original file line number Diff line number Diff line change
Expand Up @@ -238,7 +238,7 @@ def self.conflate_with_osm(stops)
way_id = tyr_locate_response[index][:edges][0][:way_id]
stop_tags = stop.tags.try(:clone) || {}
if stop_tags[:osm_way_id] != way_id
logger.info "osm_way_id changed for Stop #{stop.onestop_id}: was \"#{stop_tags[:osm_way_id]}\" now \"#{way_id}\""
log "osm_way_id changed for Stop #{stop.onestop_id}: was \"#{stop_tags[:osm_way_id]}\" now \"#{way_id}\""
end
stop_tags[:osm_way_id] = way_id
stop.update(tags: stop_tags)
Expand All @@ -259,7 +259,7 @@ def self.from_gtfs(entity, attrs={})
if onestop_id.valid? == false
old_onestop_id = onestop_id.to_s
onestop_id = OnestopId.handler_by_model(self).new(geohash: geohash, name: entity.id)
logger.info "Stop.from_gtfs: Invalid onestop_id: #{old_onestop_id}, trying #{onestop_id.to_s}"
log "Stop.from_gtfs: Invalid onestop_id: #{old_onestop_id}, trying #{onestop_id.to_s}"
end
onestop_id.validate! # raise OnestopIdException
stop = Stop.new(
Expand Down
76 changes: 35 additions & 41 deletions app/services/gtfs_graph.rb
Original file line number Diff line number Diff line change
Expand Up @@ -21,14 +21,14 @@ def initialize(feed, feed_version)
end

def cleanup
log "Cleanup any existing FeedVersion SSPs"
graph_log "Cleanup any existing FeedVersion SSPs"
@feed_version.delete_schedule_stop_pairs!
end

def create_change_osr
log "Load GTFS"
graph_log "Load GTFS"
@gtfs.load_graph
log "Load TL"
graph_log "Load TL"
load_tl_stops
load_tl_routes
rsps = load_tl_route_stop_patterns
Expand All @@ -54,44 +54,44 @@ def create_change_osr
)
end
####
log "Create changeset"
graph_log "Create changeset"
changeset = Changeset.create(
imported_from_feed: @feed,
imported_from_feed_version: @feed_version,
notes: "Changeset created by FeedEaterWorker for #{@feed.onestop_id} #{@feed_version.sha1}"
)
log "Create: Operators, Stops, Routes"
graph_log "Create: Operators, Stops, Routes"
# Update Feed Bounding Box
log " updating feed bounding box"
graph_log " updating feed bounding box"
@feed.set_bounding_box_from_stops(stops)
# FIXME: Run through changeset
@feed.save!
# Clear out serves; can't find routes that don't exist yet.
operators.each { |operator| operator.serves = nil }
log " operators: #{operators.size}"
graph_log " operators: #{operators.size}"
begin
changeset.create_change_payloads(operators)
log " stops: #{stops.size}"
graph_log " stops: #{stops.size}"
changeset.create_change_payloads(stops)
log " routes: #{routes.size}"
graph_log " routes: #{routes.size}"
changeset.create_change_payloads(routes)
log " route geometries: #{rsps.size}"
graph_log " route geometries: #{rsps.size}"
changeset.create_change_payloads(rsps)
rescue Changeset::Error => e
log "Error: #{e.message}"
log "Payload:"
graph_log "Error: #{e.message}"
graph_log "Payload:"
changeset.change_payloads.each do |change_payload|
log change_payload.to_json
graph_log change_payload.to_json
end
end
log "Changeset apply"
graph_log "Changeset apply"
t = Time.now
changeset.apply!
log " apply done: time #{Time.now - t}"
graph_log " apply done: time #{Time.now - t}"
end

def calculate_rsp_distances(rsps)
log "Calculating distances"
graph_log "Calculating distances"
rsps_with_issues = 0
rsps.each do |rsp|
stops = rsp.stop_pattern.map { |onestop_id| find_by_onestop_id(onestop_id) }
Expand All @@ -100,13 +100,13 @@ def calculate_rsp_distances(rsps)
rsp.evaluate_distances
rsps_with_issues += 1 if rsp.distance_issues > 0
rescue StandardError
log "Could not calculate distances for Route Stop Pattern: #{rsp.onestop_id}"
graph_log "Could not calculate distances for Route Stop Pattern: #{rsp.onestop_id}"
rsps_with_issues += 1
rsp.fallback_distances(stops=stops)
end
end
score = ((rsps.size - rsps_with_issues)/rsps.size.to_f).round(5) rescue score = 1.0
log "Feed: #{@feed.onestop_id}. #{rsps_with_issues} Route Stop Patterns out of #{rsps.size} had issues with distance calculation. Valhalla Import Score: #{score}"
graph_log "Feed: #{@feed.onestop_id}. #{rsps_with_issues} Route Stop Patterns out of #{rsps.size} had issues with distance calculation. Valhalla Import Score: #{score}"
end

def ssp_schedule_async
Expand All @@ -118,14 +118,14 @@ def ssp_schedule_async
end

def ssp_perform_async(trip_ids, agency_map, route_map, stop_map, rsp_map)
log "Load GTFS"
graph_log "Load GTFS"
@gtfs.agencies
@gtfs.routes
@gtfs.stops
@gtfs.trips
load_gtfs_id_map(agency_map, route_map, stop_map, rsp_map)
trips = trip_ids.map { |trip_id| @gtfs.trip(trip_id) }
log "Create: SSPs"
graph_log "Create: SSPs"
total = 0
ssps = []
@gtfs.trip_stop_times(trips=trips, filter_empty=true) do |trip,stop_times|
Expand All @@ -142,7 +142,7 @@ def ssp_perform_async(trip_ids, agency_map, route_map, stop_map, rsp_map)
origin_dist_traveled = rsp.stop_distances[i]
destination_dist_traveled = rsp.stop_distances[i+1]
rescue StandardError
log "problem with rsp #{rsp.onestop_id} stop_distances index"
graph_log "problem with rsp #{rsp.onestop_id} stop_distances index"
end
ssp_trip << make_ssp(route, trip, origin, origin_dist_traveled, destination, destination_dist_traveled, rsp)
end
Expand All @@ -152,14 +152,14 @@ def ssp_perform_async(trip_ids, agency_map, route_map, stop_map, rsp_map)
ssps += ssp_trip
# If chunk is big enough, create change payloads.
if ssps.size >= CHANGE_PAYLOAD_MAX_ENTITIES
log " ssps: #{ssps.size}"
graph_log " ssps: #{ssps.size}"
fail GTFSGraph::Error.new('Validation error') unless ssps.map(&:valid?).all?
ScheduleStopPair.import ssps, validate: false
ssps = []
end
end
if ssps.size > 0
log " ssps: #{ssps.size}"
graph_log " ssps: #{ssps.size}"
fail GTFSGraph::Error.new('Validation error') unless ssps.map(&:valid?).all?
ScheduleStopPair.import ssps, validate: false
ssps = []
Expand All @@ -176,27 +176,21 @@ def import_log

##### Logging #####

def log(msg)
def graph_log(msg)
@log << msg
if Sidekiq::Logging.logger
Sidekiq::Logging.logger.info msg
elsif Rails.logger
Rails.logger.info msg
else
puts msg
end
log(msg)
end

##### Create TL Entities #####

def load_tl_stops
# Merge child stations into parents
log " stops"
graph_log " stops"
# Create parent stops first
@gtfs.stops.reject(&:parent_station).each do |gtfs_stop|
stop = find_and_update_entity(Stop.from_gtfs(gtfs_stop))
add_identifier(stop, 's', gtfs_stop)
log " Station: #{stop.onestop_id}: #{stop.name}"
graph_log " Station: #{stop.onestop_id}: #{stop.name}"
end
# Create child stops
@gtfs.stops.select(&:parent_station).each do |gtfs_stop|
Expand All @@ -215,13 +209,13 @@ def load_tl_stops
stop = find_and_update_entity(stop)
add_identifier(stop, 's', gtfs_stop)
#
log " Stop: #{stop.onestop_id}: #{stop.name}"
graph_log " Stop: #{stop.onestop_id}: #{stop.name}"
end
end

def load_tl_operators
# Operators
log " operators"
graph_log " operators"
operators = Set.new
# key=nil is poorly defined in gtfs wrapper
agencies = Hash[@gtfs.agencies.map { |a| [a.id,a] }]
Expand Down Expand Up @@ -252,15 +246,15 @@ def load_tl_operators
# Cache Operator
# Add to found operators
operators << operator
log " #{operator.onestop_id}: #{operator.name}"
graph_log " #{operator.onestop_id}: #{operator.name}"
end
# Return operators
operators
end

def load_tl_routes
# Routes
log " routes"
graph_log " routes"
@gtfs.routes.each do |entity|
# Find: (child gtfs trips) to (child gtfs stops) to (tl stops)
stops = entity.stops.map { |stop| find_by_gtfs_entity(stop) }.to_set
Expand All @@ -283,13 +277,13 @@ def load_tl_routes
route.serves ||= Set.new
route.serves |= stops.map(&:onestop_id)
add_identifier(route, 'r', entity)
log " #{route.onestop_id}: #{route.name}"
graph_log " #{route.onestop_id}: #{route.name}"
end
end

def load_tl_route_stop_patterns
# Route Stop Patterns
log " route stop patterns"
graph_log " route stop patterns"
rsps = Set.new
stop_times_with_shape_dist_traveled = 0
stop_times_count = 0
Expand All @@ -307,7 +301,7 @@ def load_tl_route_stop_patterns
test_rsp = RouteStopPattern.create_from_gtfs(trip, tl_route.onestop_id, stop_pattern, trip_stop_points, feed_shape_points)
rsp = find_and_update_entity(test_rsp)
rsp.traversed_by = tl_route.onestop_id
log " #{rsp.onestop_id}" if test_rsp.equal?(rsp)
graph_log " #{rsp.onestop_id}" if test_rsp.equal?(rsp)
unless trip.shape_id.blank?
identifier = OnestopId::create_identifier(
@feed.onestop_id,
Expand All @@ -321,7 +315,7 @@ def load_tl_route_stop_patterns
rsp.route = tl_route
rsps << rsp
end
log "#{stop_times_with_shape_dist_traveled} stop times with shape_dist_traveled found out of #{stop_times_count} total stop times" if stop_times_with_shape_dist_traveled > 0
graph_log "#{stop_times_with_shape_dist_traveled} stop times with shape_dist_traveled found out of #{stop_times_count} total stop times" if stop_times_with_shape_dist_traveled > 0
rsps
end

Expand Down
9 changes: 9 additions & 0 deletions config/initializers/logging.rb
Original file line number Diff line number Diff line change
@@ -0,0 +1,9 @@
def log(msg, level = :info)
if Sidekiq::Logging.logger
Sidekiq::Logging.logger.send level, msg
elsif Rails.logger
Rails.logger.send level, msg
else
puts msg
end
end