{"action":"created","issue":{"url":"https://api.github.com/repos/particle-iot/firmware/issues/1497","repository_url":"https://api.github.com/repos/particle-iot/firmware","labels_url":"https://api.github.com/repos/particle-iot/firmware/issues/1497/labels{/name}","comments_url":"https://api.github.com/repos/particle-iot/firmware/issues/1497/comments","events_url":"https://api.github.com/repos/particle-iot/firmware/issues/1497/events","html_url":"https://github.com/particle-iot/firmware/issues/1497","id":303333905,"number":1497,"title":"subclassing LogHandler and implementing logMessage with code that generates logs blocks the application thread","user":{"login":"technobly","id":2249224,"avatar_url":"https://avatars2.githubusercontent.com/u/2249224?v=4","gravatar_id":"","url":"https://api.github.com/users/technobly","html_url":"https://github.com/technobly","followers_url":"https://api.github.com/users/technobly/followers","following_url":"https://api.github.com/users/technobly/following{/other_user}","gists_url":"https://api.github.com/users/technobly/gists{/gist_id}","starred_url":"https://api.github.com/users/technobly/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/technobly/subscriptions","organizations_url":"https://api.github.com/users/technobly/orgs","repos_url":"https://api.github.com/users/technobly/repos","events_url":"https://api.github.com/users/technobly/events{/privacy}","received_events_url":"https://api.github.com/users/technobly/received_events","type":"User","site_admin":false},"labels":[{"id":31563422,"url":"https://api.github.com/repos/particle-iot/firmware/labels/bug","name":"bug","color":"fc2929","default":true},{"id":533535419,"url":"https://api.github.com/repos/particle-iot/firmware/labels/confirmed","name":"confirmed","color":"1d76db","default":false}],"state":"open","locked":false,"assignee":{"login":"sergeuz","id":770094,"avatar_url":"https://avatars3.githubusercontent.com/u/770094?v=4","gravatar_id":"","url":"https://api.github.com/users/sergeuz","html_url":"https://github.com/sergeuz","followers_url":"https://api.github.com/users/sergeuz/followers","following_url":"https://api.github.com/users/sergeuz/following{/other_user}","gists_url":"https://api.github.com/users/sergeuz/gists{/gist_id}","starred_url":"https://api.github.com/users/sergeuz/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/sergeuz/subscriptions","organizations_url":"https://api.github.com/users/sergeuz/orgs","repos_url":"https://api.github.com/users/sergeuz/repos","events_url":"https://api.github.com/users/sergeuz/events{/privacy}","received_events_url":"https://api.github.com/users/sergeuz/received_events","type":"User","site_admin":false},"assignees":[{"login":"sergeuz","id":770094,"avatar_url":"https://avatars3.githubusercontent.com/u/770094?v=4","gravatar_id":"","url":"https://api.github.com/users/sergeuz","html_url":"https://github.com/sergeuz","followers_url":"https://api.github.com/users/sergeuz/followers","following_url":"https://api.github.com/users/sergeuz/following{/other_user}","gists_url":"https://api.github.com/users/sergeuz/gists{/gist_id}","starred_url":"https://api.github.com/users/sergeuz/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/sergeuz/subscriptions","organizations_url":"https://api.github.com/users/sergeuz/orgs","repos_url":"https://api.github.com/users/sergeuz/repos","events_url":"https://api.github.com/users/sergeuz/events{/privacy}","received_events_url":"https://api.github.com/users/sergeuz/received_events","type":"User","site_admin":false}],"milestone":{"url":"https://api.github.com/repos/particle-iot/firmware/milestones/34","html_url":"https://github.com/particle-iot/firmware/milestone/34","labels_url":"https://api.github.com/repos/particle-iot/firmware/milestones/34/labels","id":3046547,"number":34,"title":"0.8.0-rc.3","description":null,"creator":{"login":"m-mcgowan","id":2465470,"avatar_url":"https://avatars1.githubusercontent.com/u/2465470?v=4","gravatar_id":"","url":"https://api.github.com/users/m-mcgowan","html_url":"https://github.com/m-mcgowan","followers_url":"https://api.github.com/users/m-mcgowan/followers","following_url":"https://api.github.com/users/m-mcgowan/following{/other_user}","gists_url":"https://api.github.com/users/m-mcgowan/gists{/gist_id}","starred_url":"https://api.github.com/users/m-mcgowan/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/m-mcgowan/subscriptions","organizations_url":"https://api.github.com/users/m-mcgowan/orgs","repos_url":"https://api.github.com/users/m-mcgowan/repos","events_url":"https://api.github.com/users/m-mcgowan/events{/privacy}","received_events_url":"https://api.github.com/users/m-mcgowan/received_events","type":"User","site_admin":false},"open_issues":13,"closed_issues":0,"state":"open","created_at":"2018-01-18T20:22:30Z","updated_at":"2018-03-08T02:30:56Z","due_on":null,"closed_at":null},"comments":1,"created_at":"2018-03-08T02:30:56Z","updated_at":"2018-03-08T06:40:52Z","closed_at":null,"author_association":"OWNER","body":"## Bug Report\r\n\r\n### Expected Behavior\r\n\r\n[subclassing LogHandler and implementing logMessage with code that generates logs](https://github.com/barakwei/ParticlePapertrail/blob/master/src/papertrail.cpp#L83) should behave sanely.\r\n\r\n### Observed Behavior\r\n\r\nThe logging within the logger freezes the application thread while the LogHandler is trying to acquire a lock on the resource.\r\n\r\n### Steps to Reproduce\r\n\r\nUsing system firmware 0.8.0-rc.2 and the following app\r\n\r\nOne fix tested that worked, recompiling user firmware locally changing `Mutex mutex_` to `RecursiveMutex mutex_` from [here](https://github.com/particle-iot/firmware/blob/develop/wiring/inc/spark_wiring_logging.h#L587) and also including a flag to prevent re-entry to the logMessage function.\r\n\r\n### Test App\r\n\r\n```c\r\n#include \"Particle.h\"\r\n\r\nclass UdpThing : LogHandler\r\n{\r\nprivate:\r\n\r\n    UDP Udp;\r\n    volatile bool active;\r\n\r\npublic:\r\n\r\n    UdpThing(LogLevel level = LOG_LEVEL_INFO) :\r\n            LogHandler(level),\r\n            active(false) {\r\n    }\r\n\r\n    void begin()\r\n    {\r\n        Udp.begin(8888);\r\n    }\r\n\r\n    void addHandler() {\r\n        LogManager::instance()->addHandler(this);\r\n    }\r\n\r\n    void logMessage(const char *msg, LogLevel level, const char *category, const LogAttributes &attr)\r\n    {\r\n        if (active) {\r\n            return;\r\n        }\r\n        active = true;\r\n\r\n        Serial.printlnf(\"logger: %s\", msg);\r\n        if (millis() > 15000) {\r\n            Udp.beginPacket({8, 8, 8, 8}, 5000);\r\n            Udp.write(\"testing \");\r\n            Udp.endPacket();\r\n            Serial.println(\"application thread hangs here!!\");\r\n        }\r\n\r\n        active = false;\r\n    }\r\n\r\n};\r\n\r\nSerialLogHandler logHandler(Serial, LOG_LEVEL_ALL);  // all level over usb\r\n\r\nUdpThing udpThing;\r\n\r\nvoid setup()\r\n{\r\n    udpThing.begin();\r\n    udpThing.addHandler();\r\n}\r\n\r\nvoid loop()\r\n{\r\n    Log.info(\"%lu ping\", millis());\r\n    delay(500);\r\n}\r\n```\r\n\r\n### References\r\n\r\n[issue 1](https://github.com/barakwei/ParticlePapertrail/issues/8)\r\n[issue 2](https://github.com/barakwei/ParticlePapertrail/issues/7)\r\n[issue 3](https://community.particle.io/t/papertrail-for-electron/37508)\r\n[issue 4](https://community.particle.io/t/new-library-papertrail/28105/18?u=bdub)\r\n[issue 5](https://community.particle.io/t/help-udp-send-in-loghandler-hangs-electron-w-0-6-1/30792)\r\n"},"comment":{"url":"https://api.github.com/repos/particle-iot/firmware/issues/comments/371395073","html_url":"https://github.com/particle-iot/firmware/issues/1497#issuecomment-371395073","issue_url":"https://api.github.com/repos/particle-iot/firmware/issues/1497","id":371395073,"user":{"login":"technobly","id":2249224,"avatar_url":"https://avatars2.githubusercontent.com/u/2249224?v=4","gravatar_id":"","url":"https://api.github.com/users/technobly","html_url":"https://github.com/technobly","followers_url":"https://api.github.com/users/technobly/followers","following_url":"https://api.github.com/users/technobly/following{/other_user}","gists_url":"https://api.github.com/users/technobly/gists{/gist_id}","starred_url":"https://api.github.com/users/technobly/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/technobly/subscriptions","organizations_url":"https://api.github.com/users/technobly/orgs","repos_url":"https://api.github.com/users/technobly/repos","events_url":"https://api.github.com/users/technobly/events{/privacy}","received_events_url":"https://api.github.com/users/technobly/received_events","type":"User","site_admin":false},"created_at":"2018-03-08T06:40:52Z","updated_at":"2018-03-08T06:40:52Z","author_association":"OWNER","body":"The recursive mutex alone doesn't protect the logMessage function from re-entry, rather it's the thing that allows it.  Without the flag, the first log message generated within the logMessage function would call itself recursively until the stack overflows.  I've also tested this to be the case, and forgot to highlight this issue, but did include the `active` flag workaround.  I'm guessing we could prevent it, but it's also pretty easy to allow for some recursion if that was necessary (I can't think of how it would be used right now though, but maybe I'll ask myself and get back to you 🤣 )."}}
{"actor":{"display_login":"technobly"}}