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

Webhook not working #1750

Closed
rodrigoscoelho opened this issue Jun 30, 2020 · 28 comments
Closed

Webhook not working #1750

rodrigoscoelho opened this issue Jun 30, 2020 · 28 comments

Comments

@rodrigoscoelho
Copy link
Contributor

Hi, webhooks that were working on previous versions are not working anymore.

Anyone else with problems?

@yurikuzn
Copy link
Contributor

yurikuzn commented Jul 1, 2020

Hi Rodrigo,

There were no any changes related to webhook functionality for the last year or so.

@rodrigoscoelho
Copy link
Contributor Author

rodrigoscoelho commented Jul 1, 2020 via email

@rodrigoscoelho
Copy link
Contributor Author

Please help, the debug is not informing any problem.

[2020-07-02 20:18:36] Espo.DEBUG: Workflow\Actions: Start [updateEntity] with cid [0] for entity [GoogleSheets, 5efe2de88a1bce4e9]. [] []
[2020-07-02 20:18:36] Espo.DEBUG: Workflow\Actions: End [updateEntity] with cid [0] for entity [GoogleSheets, 5efe2de88a1bce4e9]. [] []
[2020-07-02 20:18:36] Espo.DEBUG: Workflow\ActionManager: End workflow rule ID [5d2ce3165190ff0ff]. [] []
[2020-07-02 20:18:36] Espo.DEBUG: WorkflowManager: End running Actions for workflow rule [5d2ce3165190ff0ff]. [] []
[2020-07-02 20:18:36] Espo.DEBUG: WorkflowManager: End workflow rule [5d2ce3165190ff0ff]. [] []
[2020-07-02 20:18:36] Espo.DEBUG: WorkflowManager: End workflow [afterRecordSaved] for Entity [GoogleSheets, 5efe2de88a1bce4e9]. [] []
[2020-07-02 20:19:01] Espo.INFO: CronManager: Stop cron running, too frequent execution. [] []
[2020-07-02 20:19:02] Espo.DEBUG: BPM: processPendingFlows [] []
[2020-07-02 20:19:02] Espo.DEBUG: BPM: processTriggeredSignals [] []

you can see my workflow, but nothing about the Webhook.

@yurikuzn

@yurikuzn
Copy link
Contributor

yurikuzn commented Jul 3, 2020

I tested and it worked fine on the latest version. I will be absent for 5 days or so. Suggest debugging in application/Espo/Core/Webhook. You can add log lines:

$GLOBALS['log']->debug('Some text');

@rodrigoscoelho
Copy link
Contributor Author

rodrigoscoelho commented Jul 3, 2020 via email

@yurikuzn
Copy link
Contributor

yurikuzn commented Jul 4, 2020

Check whether the scheduled job is running.

@rodrigoscoelho
Copy link
Contributor Author

As you can see on the image below. Perfect... I don't have any idea.
It was working before.

Below there is an example of webhook created. Thanks Yuri. Keep Healthy

image

image

@rodrigoscoelho
Copy link
Contributor Author

I don't know what to do anymore.
I was watching it using Pipedream, and, sporadically it post something.
So, 1 in 10 times, it posts as a webhook should do. What could it be? Any idea @yurikuzn ?

Thanks

@rodrigoscoelho
Copy link
Contributor Author

Here goes a screenshot of pipedream, showing that SOMEDAY it worked, but is not working anymore. Works very sporadic.

image

I really would like to fix this. It was working like a charm. Now it is with these problems. Any clue? Why webhook is not ALWAYS working. Why only sometimes?

Thanks.

@yurikuzn
Copy link
Contributor

yurikuzn commented Jul 15, 2020

Check 2 webhook_* tables in DB. Whether they get populated with new rows as an event of your webhook occurs (e.g. on record save).

@rodrigoscoelho
Copy link
Contributor Author

The only ones being populated are the ones that REALLY worked (as we can see on pipedream.
image
image
image

@yurikuzn
Copy link
Contributor

@rodrigoscoelho
Copy link
Contributor Author

rodrigoscoelho commented Jul 16, 2020 via email

@rodrigoscoelho
Copy link
Contributor Author

I put this line below and restarted apache and php, but nothing shows on LOG file after saving a record.

image

@rodrigoscoelho
Copy link
Contributor Author

@yurikuzn , after restarting Apache and PHP, the webhook started working again.
BUT, after some time, stopped again.
Any idea what could be??
Thanks

@yurikuzn
Copy link
Contributor

yurikuzn commented Jul 16, 2020

Does it execute afterSave? Is your debug logged?

@rodrigoscoelho
Copy link
Contributor Author

Yes, after restarting, it is debbuging. Take a look below.

[2020-07-16 15:16:33] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:33] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:33] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:33] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:33] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:34] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:34] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:47] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:47] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:47] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:47] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:47] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:48] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:16:49] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:17:01] Espo.INFO: CronManager: Stop cron running, too frequent execution. [] []

@rodrigoscoelho
Copy link
Contributor Author

Right now, I just created a new record, and it didn't push via webhook. Very weird.

apparently, it is doing a LOOPING on webhook, I don't know why, and stopping at middle, as you can see on the log below. I'm doing only 1 saving, and it gives a LOT of calls on the AFTERSAVE

[2020-07-16 15:23:48] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:23:48] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:23:49] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:23:49] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:01] Espo.INFO: CronManager: Stop cron running, too frequent execution. [] []
[2020-07-16 15:24:03] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:03] Espo.DEBUG: BPM: processPendingFlows [] []
[2020-07-16 15:24:03] Espo.DEBUG: BPM: processTriggeredSignals [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:04] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:05] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:05] Espo.DEBUG: Debugging WEBHOOK [] []
[2020-07-16 15:24:05] Espo.DEBUG: Debugging WEBHOOK [] []

@yurikuzn
Copy link
Contributor

It supposed to be called multiple times. It's not looping.

@rodrigoscoelho
Copy link
Contributor Author

what about this line?
[2020-07-16 15:24:01] Espo.INFO: CronManager: Stop cron running, too frequent execution. [] []

@yurikuzn
Copy link
Contributor

yurikuzn commented Jul 16, 2020

I don't know.

Debug deeper. Webhook manager class > process methods. Check whether they are executed on record save.

Check data/cache/application/webhooks.php file.

The logic of webhooks is not that hard. You could analyze the code, add debug logging to figure out where it fails.

@rodrigoscoelho
Copy link
Contributor Author

@yurikuzn , after some time trying to find why it is working sporadically, I found that if I ask to REBUILD BACKEND, it start to work again, and, after some hours, stops again.

I don't know if this info helps to find the cause.

In a desperate trial, yesterday I upgrade the system from Ubuntu 18.04 to Ubuntu 20.4, but, even with newer packages and libraries, the same error is happening.

No idea anymore....

@rodrigoscoelho
Copy link
Contributor Author

More info, it works until the next day. As you can see on this image, it worked all day, but, after 23:15, no more new webhook post.

image

@rodrigoscoelho
Copy link
Contributor Author

rodrigoscoelho commented Aug 2, 2020

So, @yurikuzn , please, since I CONFIRMED that it starts working again after asking to REBUILD BACKEND, and stops again after some hours, at least I can put on cron to rebuild it from time to time.
What would I lose if I do this? How to do this using the console?

Thanks.

@eymen-elkum
Copy link
Contributor

eymen-elkum commented Aug 3, 2020

What would I lose if I do this?

Nothing (must nothing)

How to do this using the console?

Try this:
0 */5 * * * cd /home/your/crm; /opt/alt/php72/usr/bin/php -f rebuild.php > /dev/null 2>&1

NOTE:
In such problems that take a long time from you I strongly recommend to have a parallel fresh copy of espocrm to test with, some problems may related to the environment so you can make sure it is related to espocrm, environment or config.

If the problem cannot reproduced with the fresh copy of crm then it is most probably not related to espocrm itself.

@rodrigoscoelho
Copy link
Contributor Author

What would I lose if I do this?

Nothing (must nothing)

How to do this using the console?

Try this:
0 */5 * * * cd /home/your/crm; /opt/alt/php72/usr/bin/php -f rebuild.php > /dev/null 2>&1

NOTE:
In such problems that take a long time from you I strongly recommend to have a parallel fresh copy of espocrm to test with, some problems may related to the environment so you can make sure it is related to espocrm, environment or config.

If the problem cannot reproduced with the fresh copy of crm then it is most probably not related to espocrm itself.

Thank you so much @eymen-elkum. Are you working on EspoCRM.

Kind regards,

@eymen-elkum
Copy link
Contributor

eymen-elkum commented Aug 4, 2020

Are you working on EspoCRM

Yes, I am working on new extensions.

@rodrigoscoelho
Copy link
Contributor Author

rodrigoscoelho commented Aug 4, 2020 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants