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.

Sign up for GitHub

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

Debug logging subscriptions #979

Closed
wants to merge 3 commits into from
Closed

Debug logging subscriptions #979

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
7c36f8e
debug logging subscriptions
mickmister Oct 3, 2023
d34310b
more debug logging
mickmister Oct 4, 2023
45d5ce4
lint
mickmister Oct 4, 2023
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
47 changes: 45 additions & 2 deletions server/subscribe.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -124,31 +124,46 @@ func (p *Plugin) getUserID() string {
return p.getConfig().botUserID
}

func (p *Plugin) matchesSubsciptionFilters(wh *webhook, filters SubscriptionFilters) bool {
func (p *Plugin) matchesSubsciptionFilters(wh *webhook, sub ChannelSubscription) bool {
filters := sub.Filters

subCheckID := model.NewId()
log := func(msg interface{}) {
p.client.Log.Debug("matchesSubsciptionFilters DEBUG LOG", "issue_id", wh.Issue.ID, "sub_check_id", subCheckID, "msg", msg, "sub_name", sub.Name)
}

log(1)

webhookEvents := wh.Events()
foundEvent := false
eventTypes := filters.Events
if eventTypes.Intersection(webhookEvents).Len() > 0 {
log(2)
foundEvent = true
} else if eventTypes.ContainsAny(eventUpdatedAny) {
log(3)
for _, eventType := range webhookEvents.Elems() {
if strings.HasPrefix(eventType, "event_updated") || strings.HasSuffix(eventType, "comment") {
log("4 " + eventType)
foundEvent = true
}
}
}

if !foundEvent {
log(5)
return false
}

issue := &wh.JiraWebhook.Issue

if filters.IssueTypes.Len() != 0 && !filters.IssueTypes.ContainsAny(issue.Fields.Type.ID) {
log(6)
return false
}

if filters.Projects.Len() != 0 && !filters.Projects.ContainsAny(issue.Fields.Project.Key) {
log(7)
return false
}

Expand All @@ -159,29 +174,39 @@ func (p *Plugin) matchesSubsciptionFilters(wh *webhook, filters SubscriptionFilt

// Broken filter, values must be provided
if inclusion == "" || (field.Values.Len() == 0 && inclusion != FilterEmpty) {
log(8)
return false
}

if field.Key == securityLevelField {
containsSecurityLevelFilter = true
log(9)

if inclusion == FilterExcludeAny && useEmptySecurityLevel {
log(10)
inclusion = FilterEmpty
}
}

value := getIssueFieldValue(issue, field.Key)
if !isValidFieldInclusion(field, value, inclusion) {
log(11)
log(fmt.Sprintf("field %s value %s inclusion %s", field.Key, value.Elems(), inclusion))
return false
}
}

if !containsSecurityLevelFilter && useEmptySecurityLevel {
securityLevel := getIssueFieldValue(issue, securityLevelField)
log(12)
if securityLevel.Len() > 0 {
log(13)
return false
}
}

log(14)

return true
}

Expand All @@ -200,19 +225,27 @@ func isValidFieldInclusion(field FieldFilter, value StringSet, inclusion string)
}

func (p *Plugin) getChannelsSubscribed(wh *webhook, instanceID types.ID) ([]ChannelSubscription, error) {
p.API.LogDebug("getChannelsSubscribed 1")
subs, err := p.getSubscriptions(instanceID)
if err != nil {
p.API.LogDebug("getChannelsSubscribed 2")
return nil, err
}

p.API.LogDebug("getChannelsSubscribed 3", "lensubs", len(subs.Channel.ByID))

var channelSubscriptions []ChannelSubscription
subIds := subs.Channel.ByID
for _, sub := range subIds {
if p.matchesSubsciptionFilters(wh, sub.Filters) {
if p.matchesSubsciptionFilters(wh, sub) {
channelSubscriptions = append(channelSubscriptions, sub)
p.client.Log.Debug("matches for sub " + sub.Name)
} else {
p.client.Log.Debug("does not match for sub " + sub.Name)
}
}

p.API.LogDebug("getChannelsSubscribed 4")
return channelSubscriptions, nil
}

Expand Down Expand Up @@ -747,16 +780,22 @@ func (p *Plugin) hasPermissionToManageSubscription(instanceID types.ID, userID,
func (p *Plugin) httpSubscribeWebhook(w http.ResponseWriter, r *http.Request, instanceID types.ID) (status int, err error) {
conf := p.getConfig()

p.client.Log.Debug("httpSubscribeWebhook 1")

if conf.Secret == "" {
return respondErr(w, http.StatusForbidden,
fmt.Errorf("JIRA plugin not configured correctly; must provide Secret"))
}

p.client.Log.Debug("httpSubscribeWebhook 2")

status, err = verifyHTTPSecret(conf.Secret, r.FormValue("secret"))
if err != nil {
return respondErr(w, status, err)
}

p.client.Log.Debug("httpSubscribeWebhook 3")

bb, err := io.ReadAll(r.Body)
if err != nil {
return respondErr(w, http.StatusInternalServerError, err)
Expand All @@ -765,15 +804,19 @@ func (p *Plugin) httpSubscribeWebhook(w http.ResponseWriter, r *http.Request, in
p.client.Log.Debug("Webhook Event Log", "event", string(bb))
}

p.client.Log.Debug("httpSubscribeWebhook 4")

// If there is space in the queue, immediately return a 200; we will process the webhook event async.
// If the queue is full, return a 503; we will not process that webhook event.
select {
case p.webhookQueue <- &webhookMessage{
InstanceID: instanceID,
Data: bb,
}:
p.client.Log.Debug("httpSubscribeWebhook webhook event queued")
return http.StatusOK, nil
default:
p.client.Log.Debug("httpSubscribeWebhook webhook event not queued")
return respondErr(w, http.StatusServiceUnavailable, nil)
}
}
Expand Down
11 changes: 11 additions & 0 deletions server/webhook_worker.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ type webhookMessage struct {

func (ww webhookWorker) work() {
for msg := range ww.workQueue {
ww.p.client.Log.Debug("webhookWorker.work")
err := ww.process(msg)
if err != nil {
if errors.Is(err, errWebhookeventUnsupported) {
Expand All @@ -41,31 +42,41 @@ func (ww webhookWorker) process(msg *webhookMessage) (err error) {
}
}()

ww.p.client.Log.Debug("webhookWorker.process 1")

wh, err := ParseWebhook(msg.Data)
if err != nil {
ww.p.client.Log.Debug("webhookWorker.process 2")
return err
}

if _, _, err = wh.PostNotifications(ww.p, msg.InstanceID); err != nil {
ww.p.client.Log.Debug("webhookWorker.process 3")
ww.p.errorf("WebhookWorker id: %d, error posting notifications, err: %v", ww.id, err)
}

v := wh.(*webhook)
if err = v.JiraWebhook.expandIssue(ww.p, msg.InstanceID); err != nil {
ww.p.client.Log.Debug("webhookWorker.process 4")
return err
}

channelsSubscribed, err := ww.p.getChannelsSubscribed(v, msg.InstanceID)
if err != nil {
ww.p.client.Log.Debug("webhookWorker.process 5")
return err
}

ww.p.client.Log.Debug("webhookWorker.process 6", "len_channels_subscribed", len(channelsSubscribed))

botUserID := ww.p.getUserID()
for _, channelSubscribed := range channelsSubscribed {
if _, _, err1 := wh.PostToChannel(ww.p, msg.InstanceID, channelSubscribed.ChannelID, botUserID, channelSubscribed.Name); err1 != nil {
ww.p.client.Log.Debug("webhookWorker.process 7")
ww.p.errorf("WebhookWorker id: %d, error posting to channel, err: %v", ww.id, err1)
}
}

ww.p.client.Log.Debug("webhookWorker.process 8")
return nil
}
Loading