search

noahd1 / oink

Log parser to identify actions which significantly increase VM heap size
MIT License
1.18k stars 71 forks source link

Incorrect parsing of logs? #31

Closed sgringwe closed 10 years ago

sgringwe commented 10 years ago

I am using oink after running a bunch of request specs to benchmark/profile various controllers actions. One result that I get back after running

bundle exec oink -r --threshold=50 --format=v log/oink.log

is

May 04 15:31:18 box6 rails[7603]: Oink Action: sessions#new
May 04 15:31:18 box6 rails[7603]: Memory usage: 1358100 | PID: 7603
May 04 15:31:18 box6 rails[7603]: Instantiation Breakdown: Total: 9164 | User: 2081 | School: 1385 | Employer: 946 | Communication: 777 | SchoolYear: 422 | Posting: 397 | StudentScreen: 351 | InterviewSchedule: 286 | Job: 263 | InterviewScheduleType: 263 | JobType: 241 | EmployerApproval: 117 | Education: 111 | RolePermission: 105 | Major: 91 | InterviewScheduleInvite: 81 | Event: 76 | HABTM_Majors: 70 | Role: 66 | EducationLevel: 65 | Building: 64 | Room: 61 | EventType: 59 | InterviewSlot: 56 | HABTM_Roles: 51 | InternalMessage: 44 | Conversation: 42 | Application: 40 | CommunicationType: 39 | MassEmail: 34 | Skill: 31 | NotificationReason: 31 | Activity: 30 | SavedSearch: 25 | Report: 24 | EventTime: 23 | CareerPlan: 23 | MajorGroup: 21 | NotificationCategory: 20 | Attendee: 18 | NotificationPreference: 15 | WorkAuthorization: 14 | JobPosition: 13 | EmailTemplate: 12 | InstitutionContact: 12 | Notification: 11 | ExtraCurricularPosition: 10 | WorkExperience: 9 | ExtraCurricularActivity: 8 | CareerPlanCategory: 8 | ExtraCurricularCategory: 8 | FeedItem: 8 | Location: 7 | Minor: 6 | Invite: 6 | AuthInformation: 6 | Label: 6 | PlanItem: 6 | InstitutionLabel: 6 | SkillOption: 5 | SchoolMajor: 5 | InterviewScheduleCheckin: 4 | ExtraCurricular: 4 | Resume: 4 | PlanItemCompletion: 4 | HABTM_WorkAuthorizations: 4 | EmployerFlag: 4 | InterviewScheduleInterviewer: 4 | StudentReview: 4 | Survey: 3 | Project: 3 | Industry: 2 | Favorite: 2 | InterviewScheduleJob: 2 | InstitutionType: 2 | InstitutionSize: 2 | HABTM_Minors: 2 | ApiKey: 1 | ResumeParsing: 1 | AuditLog: 1
May 04 15:31:18 box6 rails[7603]: Oink Log Entry Complete

This does not seem correct. Is it possible that oink is parsing wrong? I use the sessions#new url to log in at the beginning most of my specs.

Thanks for the awesome gem

sgringwe commented 10 years ago

Nevermind about this. I think what is happening is all the unit test instantiations are being recorded (which run before the request specs) and then when the first request is made for the request specs, they all are included.