sendMail trying to download attachments four times every time

Setup, Configuration and Use Scripts & Rules
1

I have the following rule:

rule "Driveway Laser 1 Trigger"
when
        Item DrivewayLaser1Status changed to CLOSED
then
    var String Timestamp = df.format( new Date() )

    /* Email photo from Driveway CCTV, but only once every 15 seconds */
    if(DrivewayLaser1EmailTimer == null || DrivewayLaser1EmailTimer.hasTerminated) {
        sendMail("me@me.com", "Driveway Laser Triggered " + Timestamp, "The driveway laser has been triggered on " + Timestamp + ".", "http://camera.local.ip.addy/onvif/snapshot")
        DrivewayLaser1EmailTimer = createTimer(now.plusSeconds(15), [|
            DrivewayLaser1EmailTimer = null
        ])
    }
end

The rule technically works, but the problem I’ve got is the sendMail() appears to download the attachment 4 times, and only send the last one.

eg, the clock on the camera and the openhab server are synced, An email will turn up with the Timestamp variable being 2017-04-08 18:36:13, but the camera time will be 2017-04-08 18:36:21. Due to the nature of what this is trying to trigger it often means the picture I get is too late.

Debug logs below, is it potentially not getting the right mime to start with and then constantly retrying? Is this potentially a bug with sendMail? If it sent the first image it tried to download everything would be good!

2017-04-08 19:01:36.827 [ItemStateChangedEvent     ] - DrivewayLaser1Status changed from OPEN to CLOSED
2017-04-08 19:01:36.829 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2017-04-08 19:01:37.257 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@20f78eb35 pairs: {GET /onvif/snapshot HTTP/1.1: null}{User-Agent: Java/1.8.0_121}{Host: openhab.server.ip.addy}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Connection: keep-alive}
2017-04-08 19:01:38.170 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@4074d1e3 pairs: {null: HTTP/1.1 200 OK}{Content-Type: image/jpeg}{Content-Length: 326820}
2017-04-08 19:01:38.172 [DEBUG] [javax.activation                    ] - MailcapCommandMap: createDataContentHandler for text/plain
2017-04-08 19:01:38.172 [DEBUG] [javax.activation                    ] -   search DB #1
2017-04-08 19:01:38.172 [DEBUG] [javax.activation                    ] -     got content-handler
2017-04-08 19:01:38.172 [DEBUG] [javax.activation                    ] -       class com.sun.mail.handlers.text_plain
2017-04-08 19:01:38.174 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@219b54485 pairs: {GET /onvif/snapshot HTTP/1.1: null}{User-Agent: Java/1.8.0_121}{Host: openhab.server.ip.addy}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Connection: keep-alive}
2017-04-08 19:01:39.216 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@3d05d4de3 pairs: {null: HTTP/1.1 200 OK}{Content-Type: image/jpeg}{Content-Length: 324668}
2017-04-08 19:01:39.216 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@35411dd5 pairs: {GET /onvif/snapshot HTTP/1.1: null}{User-Agent: Java/1.8.0_121}{Host: openhab.server.ip.addy}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Connection: keep-alive}
2017-04-08 19:01:40.151 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@65820b7f3 pairs: {null: HTTP/1.1 200 OK}{Content-Type: image/jpeg}{Content-Length: 325024}
2017-04-08 19:01:43.732 [DEBUG] [javax.activation                    ] - MailcapCommandMap: createDataContentHandler for multipart/mixed
2017-04-08 19:01:43.732 [DEBUG] [javax.activation                    ] -   search DB #1
2017-04-08 19:01:43.732 [DEBUG] [javax.activation                    ] -   search DB #2
2017-04-08 19:01:43.732 [DEBUG] [javax.activation                    ] -   search fallback DB #1
2017-04-08 19:01:43.733 [DEBUG] [javax.activation                    ] -     got content-handler
2017-04-08 19:01:43.733 [DEBUG] [javax.activation                    ] -       class com.sun.mail.handlers.multipart_mixed
2017-04-08 19:01:43.733 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@688efa535 pairs: {GET /onvif/snapshot HTTP/1.1: null}{User-Agent: Java/1.8.0_121}{Host: openhab.server.ip.addy}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Connection: keep-alive}
2017-04-08 19:01:44.166 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@3dd1504e3 pairs: {null: HTTP/1.1 200 OK}{Content-Type: image/jpeg}{Content-Length: 324760}
2017-04-08 19:01:46.111 [DEBUG] [rg.openhab.action.mail.internal.Mail] - Sent email to 'me@me.com' with subject 'Driveway Laser Triggered 2017-04-08 19:01:36'.

Versions FYI:

openhab> bundle:list -s | grep openhab
166 | Active   |  90 | 2.0.0                 | openHAB Core                                           | org.openhab.core
167 | Active   |  80 | 2.0.0                 | openHAB Karaf Integration                              | org.openhab.core.karaf
169 | Resolved |  80 | 2.0.0                 | openHAB Sound Support, Hosts: 111                      | org.openhab.io.sound
170 | Active   |  80 | 2.0.0                 | openHAB Dashboard UI                                   | org.openhab.ui.dashboard
176 | Active   |  80 | 2.0.0                 | openHAB 1.x Compatibility Layer                        | org.openhab.core.compat1x
200 | Active   |  80 | 2.0.0                 | openHAB REST Documentation                             | org.openhab.io.rest.docs
201 | Resolved |  80 | 2.0.0                 | openHAB Basic UI Fragment, Hosts: 197                  | org.openhab.ui.basicui
202 | Active   |  80 | 2.0.0                 | openHAB Classic UI Fragment                            | org.openhab.ui.classicui
203 | Active   |  80 | 2.0.0                 | HABmin User Interface                                  | org.openhab.ui.habmin
204 | Active   |  80 | 2.0.0                 | HABPanel User Interface                                | org.openhab.ui.habpanel
205 | Resolved |  80 | 2.0.0                 | openHAB Paper UI Theme Fragment, Hosts: 199            | org.openhab.ui.paperui
209 | Active   |  80 | 1.9.0.201701200211    | openHAB Piface Binding                                 | org.openhab.binding.piface
210 | Active   |  80 | 1.9.0                 | openHAB Mail Action                                    | org.openhab.action.mail
211 | Active   |  80 | 1.9.0                 | openHAB Twitter Action                                 | org.openhab.action.twitter
213 | Active   |  80 | 2.0.0                 | ZWave Binding                                          | org.openhab.binding.zwave
214 | Active   |  80 | 1.9.0                 | openHAB Serial Binding                                 | org.openhab.binding.serial
215 | Active   |  80 | 1.9.0                 | openHAB MQTT Binding                                   | org.openhab.binding.mqtt
216 | Active   |  80 | 1.9.0                 | openHAB MQTT Transport Bundle                          | org.openhab.io.transport.mqtt
217 | Active   |  80 | 1.9.0                 | openHAB RRD4j Persistence Bundle                       | org.openhab.persistence.rrd4j
218 | Active   |  80 | 1.9.0                 | openHAB InfluxDB Persistence bundle                    | org.openhab.persistence.influxdb
219 | Active   |  80 | 2.0.0                 | Network Binding                                        | org.openhab.binding.network
2

As the intention of this is I think to block repeat rule entries … it’d be smart to set it up before going into possibly time consuming email construction.

3

Yes, at the top of the rules file that is declared (along with others for other rules) as null, apologies if that wasn’t clear.

Relatively confident that has nothing to do with my issue as the sendMail command appears to be doing different things each time it tries to download the CCTV image.

4

To be clear. I meant to minimize the time spent “doing stuff” before applying the re-entrancy timer

rule "Driveway Laser 1 Trigger"
when
        Item DrivewayLaser1Status changed to CLOSED
then
    /* Email photo from Driveway CCTV, but only once every 15 seconds */
    if(DrivewayLaser1EmailTimer == null || DrivewayLaser1EmailTimer.hasTerminated) {
        DrivewayLaser1EmailTimer = createTimer(now.plusSeconds(15), [|
            DrivewayLaser1EmailTimer = null
        ])
        var String Timestamp = df.format( new Date() )
        sendMail("me@me.com", "Driveway Laser Triggered " + Timestamp, "The driveway laser has been triggered on " + Timestamp + ".", "http://camera.local.ip.addy/onvif/snapshot")
    }
end

the suspicion being reentrancy based upon the complaint of multiple image fetches.

You might need to implement a proper reentrant lock here, but you could add logInfo to trace before going that far.

5

Got you. Thanks, will change my scripts around and add some logging.

edit Unfortunately no difference. It just appears to be that sendMail is taking a long time to download attachments as it appears to be doing it four times, every time. I added logInfo statements around the sendMail and sendDirectMessage functions I’ve got:

11:34:51.542 [INFO ] [marthome.event.ItemStateChangedEvent] - DrivewayLaser1Status changed from OPEN to CLOSED
11:34:51.613 [INFO ] [smarthome.model.script.DrivewayLaser] - Sending tweet for DrivewayLaser1Status
11:34:52.105 [INFO ] [smarthome.model.script.DrivewayLaser] - Tweet sent for DrivewayLaser1Status
11:34:52.106 [INFO ] [smarthome.model.script.DrivewayLaser] - Sending email for DrivewayLaser1Status
11:35:01.160 [INFO ] [smarthome.model.script.DrivewayLaser] - Email sent for DrivewayLaser1Status
6

I resolved my problem by using curl to download the attachment locally then attaching it:

executeCommandLine("/usr/bin/curl -o /tmp/"+ Timestamp +".jpg http://camera.local.ip.addy/onvif/snapshot")
Thread::sleep(1000)
sendMail("me@me.com", "Driveway Laser Triggered " + Timestamp, "The driveway laser has been triggered on " + Timestamp + ".", "file:///tmp/"+ Timestamp +".jpg")

Would break if it took longer than 1000ms to download but generally it’s completed in ~300.