search

ontometrics / slack-youtrack

Integration of slack and you track.
49 stars 14 forks source link

Cannot get this working... any ideas? #4

Closed shawn-simon closed 9 years ago

shawn-simon commented 9 years ago

This is my application log. it seems to be connecting to youtrack but not finding any thing to send to slack.

2015-05-02 02:34:41,543 - [INFO] - from com.ontometrics.integrations.jobs.EventListenerImpl in Timer-0
Found 0 edit sessions to post.

2015-05-02 02:34:41,543 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing finished

2015-05-02 02:35:41,517 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing started

2015-05-02 02:35:41,517 - [DEBUG] - from com.ontometrics.integrations.sources.EditSessionsExtractor in Timer-0
edits since: Sat May 02 01:35:41 UTC 2015

2015-05-02 02:35:41,543 - [INFO] - from com.ontometrics.integrations.jobs.EventListenerImpl in Timer-0
Found 0 edit sessions to post.

2015-05-02 02:35:41,543 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing finished

2015-05-02 02:36:41,517 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing started

2015-05-02 02:36:41,518 - [DEBUG] - from com.ontometrics.integrations.sources.EditSessionsExtractor in Timer-0
edits since: Sat May 02 01:36:41 UTC 2015

2015-05-02 02:36:41,547 - [INFO] - from com.ontometrics.integrations.jobs.EventListenerImpl in Timer-0
Found 0 edit sessions to post.

2015-05-02 02:36:41,547 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing finished

2015-05-02 02:37:41,518 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing started

2015-05-02 02:37:41,518 - [DEBUG] - from com.ontometrics.integrations.sources.EditSessionsExtractor in Timer-0
edits since: Sat May 02 01:37:41 UTC 2015

2015-05-02 02:37:41,543 - [INFO] - from com.ontometrics.integrations.jobs.EventListenerImpl in Timer-0
Found 0 edit sessions to post.

2015-05-02 02:37:41,543 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing finished

my config:

mvn -DYOUTRACK_USERNAME='root' \ 
    -DYOUTRACK_PASSWORD='redacted' \
    -DSLACK_AUTH_TOKEN='redacted' \ 
    -DAPP_DATA_DIR='/home/ubuntu/yt2slack/data' \
    -DYOUTRACK_HOST='https://mydomain.myjetbrains.com/youtrack' \
    -DYOUTRACK_PORT=80 \
    -DDEFAULT_SLACK_CHANNEL='general'
    -DISSUE_HISTORY_WINDOW=60 \
    -Dmaven.test.skip=true \ 
    package
codeslubber commented 9 years ago

My guess is that the window calculation is wrong. We will figure this out. Sorry..

andrey-chorniy commented 9 years ago

Please try to do following

  1. start yourtrack and slack-youtrack app
  2. create new issue or make comment to existent one And check if issue still exists (app process only event created during time-window in the past, older ones are skipped)

If issue still exists, please refer to https://github.com/ontometrics/slack-youtrack#troubleshooting and send detailed logs

shawn-simon commented 9 years ago

@andrey-chorniy I updated the logging to requests, but not seeing where they're logged. Here's my logs. I updated some issues in YouTrack after starting the server.

~/yt2slack/logs$ ls
application.log          localhost.2015-05-04.log
catalina.2015-05-04.log  localhost_access_log.2015-05-04.txt
catalina.out

application.log

~/yt2slack/logs$ cat application.log
2015-05-04 20:27:20,361 - [INFO] - from com.ontometrics.integrations.jobs.WebContextJobStarter in localhost-startStop-1
Started up

2015-05-04 20:27:20,716 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in localhost-startStop-1
Scheduling EventListener task

2015-05-04 20:27:22,717 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing started

2015-05-04 20:27:22,719 - [INFO] - from com.ontometrics.integrations.configuration.EventProcessorConfiguration in Timer-0
Going to load properties from file /home/ubuntu/yt2slack/data/lastEvent.properties

2015-05-04 20:27:22,905 - [INFO] - from com.ontometrics.integrations.configuration.EventProcessorConfiguration in Timer-0
Last Event Change keyset:

2015-05-04 20:27:22,905 - [INFO] - from com.ontometrics.integrations.configuration.EventProcessorConfiguration in Timer-0
Initialized EventProcessorConfiguration

2015-05-04 20:27:22,906 - [DEBUG] - from com.ontometrics.integrations.sources.EditSessionsExtractor in Timer-0
edits since: Mon May 04 19:27:22 UTC 2015

2015-05-04 20:27:23,599 - [INFO] - from com.ontometrics.integrations.jobs.EventListenerImpl in Timer-0
Found 0 edit sessions to post.

2015-05-04 20:27:23,600 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing finished

2015-05-04 20:28:22,717 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing started

2015-05-04 20:28:22,717 - [DEBUG] - from com.ontometrics.integrations.sources.EditSessionsExtractor in Timer-0
edits since: Mon May 04 19:28:22 UTC 2015

2015-05-04 20:28:22,744 - [INFO] - from com.ontometrics.integrations.jobs.EventListenerImpl in Timer-0
Found 0 edit sessions to post.

2015-05-04 20:28:22,744 - [INFO] - from com.ontometrics.integrations.jobs.JobStarter in Timer-0
Event processing finished

catalina.out

~/yt2slack/logs$ cat catalina.out
May 04, 2015 8:27:15 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/common/classes], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:27:15 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/common], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:27:16 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/server/classes], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:27:16 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/server], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:27:16 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/shared/classes], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:27:16 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/shared], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:27:16 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
May 04, 2015 8:27:17 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 861 ms
May 04, 2015 8:27:17 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
May 04, 2015 8:27:17 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.52 (Ubuntu)
May 04, 2015 8:27:17 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /home/ubuntu/yt2slack/webapps/slack.war
2015-05-04 20:27:20,361 - [INFO] - c.o.i.j.WebContextJobStarter - Started up
2015-05-04 20:27:20,716 - [INFO] - c.o.i.j.JobStarter - Scheduling EventListener task
2015-05-04 20:27:22,717 - [INFO] - c.o.i.j.JobStarter - Event processing started
2015-05-04 20:27:22,719 - [INFO] - c.o.i.c.EventProcessorConfiguration - Going to load properties from file /home/ubuntu/yt2slack/data/lastEvent.properties
2015-05-04 20:27:22,905 - [INFO] - c.o.i.c.EventProcessorConfiguration - Last Event Change keyset:

2015-05-04 20:27:22,905 - [INFO] - c.o.i.c.EventProcessorConfiguration - Initialized EventProcessorConfiguration
2015-05-04 20:27:22,906 - [DEBUG] - c.o.i.s.EditSessionsExtractor - edits since: Mon May 04 19:27:22 UTC 2015
2015-05-04 20:27:23,599 - [INFO] - c.o.i.j.EventListenerImpl - Found 0 edit sessions to post.
2015-05-04 20:27:23,600 - [INFO] - c.o.i.j.JobStarter - Event processing finished
May 04, 2015 8:28:19 PM org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [58,579] milliseconds.
May 04, 2015 8:28:19 PM org.apache.jasper.EmbeddedServletOptions <init>
SEVERE: The scratchDir you specified: /home/ubuntu/yt2slack/work/Catalina/localhost/slack is unusable.
May 04, 2015 8:28:19 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
May 04, 2015 8:28:19 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 62348 ms
2015-05-04 20:28:22,717 - [INFO] - c.o.i.j.JobStarter - Event processing started
2015-05-04 20:28:22,717 - [DEBUG] - c.o.i.s.EditSessionsExtractor - edits since: Mon May 04 19:28:22 UTC 2015
2015-05-04 20:28:22,744 - [INFO] - c.o.i.j.EventListenerImpl - Found 0 edit sessions to post.
2015-05-04 20:28:22,744 - [INFO] - c.o.i.j.JobStarter - Event processing finished
2015-05-04 20:29:22,717 - [INFO] - c.o.i.j.JobStarter - Event processing started
2015-05-04 20:29:22,718 - [DEBUG] - c.o.i.s.EditSessionsExtractor - edits since: Mon May 04 19:29:22 UTC 2015
2015-05-04 20:29:22,746 - [INFO] - c.o.i.j.EventListenerImpl - Found 0 edit sessions to post.
2015-05-04 20:29:22,746 - [INFO] - c.o.i.j.JobStarter - Event processing finished

catalina.2015-05-04.txt

May 04, 2015 8:31:45 PM org.apache.coyote.AbstractProtocol pause
INFO: Pausing ProtocolHandler ["http-bio-8080"]
May 04, 2015 8:31:45 PM org.apache.catalina.core.StandardService stopInternal
INFO: Stopping service Catalina
May 04, 2015 8:31:45 PM org.apache.coyote.AbstractProtocol stop
INFO: Stopping ProtocolHandler ["http-bio-8080"]
May 04, 2015 8:31:45 PM org.apache.coyote.AbstractProtocol destroy
INFO: Destroying ProtocolHandler ["http-bio-8080"]
May 04, 2015 8:31:48 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/common/classes], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:31:48 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/common], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:31:48 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/server/classes], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:31:48 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/server], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:31:48 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/shared/classes], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:31:48 PM org.apache.catalina.startup.ClassLoaderFactory validateFile
WARNING: Problem with directory [/usr/share/tomcat7/shared], exists: [false], isDirectory: [false], canRead: [false]
May 04, 2015 8:31:49 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
May 04, 2015 8:31:49 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 865 ms
May 04, 2015 8:31:49 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
May 04, 2015 8:31:49 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.52 (Ubuntu)
May 04, 2015 8:31:49 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /home/ubuntu/yt2slack/webapps/slack.war
May 04, 2015 8:31:52 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
May 04, 2015 8:31:52 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 3093 ms

nothing in the localhost logs

shawn-simon commented 9 years ago

Thanks for your help btw!

codeslubber commented 9 years ago

Looks like it's looking for stuff that just happened today, per what we suspected.. ?

codeslubber commented 9 years ago

Looks like these are still just INFO logs, but clearly it's starting the server and looking backwards only a few minutes.

shawn-simon commented 9 years ago

Right, but I'm making updates in YouTrack after the server is running, and it's not picking anything up

codeslubber commented 9 years ago

Uh, ok, then scratch that theory.

Are we sure the YouTrack URL is correct? Probably DEBUG logs are the next thing.

shawn-simon commented 9 years ago

Yea, I'm pretty sure the YouTrack URL is correct because there are exceptions in the log if I change it. Where would I find the DEBUG logs? I already uncommented those lines and rebuilt the war file.

codeslubber commented 9 years ago

After uncommenting and rebuilding, if you redeploy DEBUG messages should appear in the same logs.

shawn-simon commented 9 years ago

Yea, I did that, and I'm not seeing the request / response logging in any of the /logs/ files : (

shawn-simon commented 9 years ago

wonder if this is the issue:

Failed tests: testThatMinimumAllowedDateCorrectlyResolved(com.ontometrics.integrations.configuration.EventProcessorConfigurationTest): Dates are not equals

Tests run: 53, Failures: 1, Errors: 0, Skipped: 3

chorniyn commented 9 years ago

@shawn-simon, we have made several changes to the logging. Now, after you update the source code in logback.xml, please uncomment these lines for HTTP request logging:

<logger name="org.apache.http" level="DEBUG" />
<logger name="com.ontometrics.integration.youtrack.response" level="DEBUG" />

Please attach logs after you redeploy application with the new logging settings.

Also, are the time zones on your Tomcat web app server and YouTrack server different? Are YT and slack-integration apps deployed on the same server?

shawn-simon commented 9 years ago

@nchorniy I already have uncommented those lines, they did not change the logging... I noticed that in the code you pasted the logger name is org.apache.http, com.ontometrics.integration.youtrack.response, but in github its:

    <!-- Uncomment line below to enable logging of sent and received data-$
    <logger name="org.apache.http.wire" level="DEBUG" />

    <!-- Uncomment line below to enable http requests headers logging-->
    <logger name="org.apache.http.headers" level="DEBUG" />

Also, are the time zones on your Tomcat web app server and YouTrack server different? Are YT and slack-integration apps deployed on the same server?

I am using cloud hosted youtrack. I just threw up an ec2 instance and installed tomcat.

shawn-simon commented 9 years ago

Oops! didnt see you just pushed. Trying again

shawn-simon commented 9 years ago

Ok... figured it out... it's concatenating the url incorrectly. My installation is not at the web root... it's putting the port in anyway. GG

Got response from url https://mysubdomain.myjetbrains.com/youtrack:80/_rss/issues

:cry:

shawn-simon commented 9 years ago

After reading the source, I set the PORT config to 0 which doesn't do the string concatenation. I would recommend expecting that the base url may have a sub path. Thanks so much for your help!

andrey-chorniy commented 9 years ago

@shawn-simon we updated the way app is configured to address that issue, now you have to provide only one parameter YOUTRACK_URL=https://mysubdomain.myjetbrains.com/youtrack or with port YOUTRACK_URL=https://mysubdomain.myjetbrains.com:443/youtrack