Problems getting HTTP response on Argon and Boron

Im trying to implement a LogHandler to enable logging to a SEQ logging server, see http://getseq.net . I have used the code for the PaperTrail Log handler as a template.

I have tried, and managed to send the data to the server in the main loop using HttpClient version 0.0.5, but when try to do the same within the log method the HTTP client hangs receiving the response from the SEQ server.

I have added some extra logging to the HTTP client to see whats happening. I have also added a SerialLogHandler to see the system messages.,

The response is 262 characters long and while iterating this loop

 while (client.available()) {
        #ifdef LOGGING
        Serial.print("Reading character #");
        Serial.print(client.available());
        #endif
        char c = client.read();
        #ifdef LOGGING
        Serial.print(", Character: ");
        Serial.print(c);
        Serial.print(" , ");
        Serial.print(client.available());
        Serial.println(" , Characters left: ");
        #endif
        lastRead = millis();

        if (c == -1) {
            error = true;

            #ifdef LOGGING
            Serial.println("HttpClient>\tError: No data available.");
            #endif

            break;
        }

        // Check that received character fits in buffer before storing.
        if (bufferPosition < sizeof(buffer)-1) {
            #ifdef LOGGING
            Serial.print("HttpClient>\tAdding character# ");
            Serial.print(bufferPosition);
            Serial.println(" to Buffer.");
            #endif
            buffer[bufferPosition] = c;
        } else if ((bufferPosition == sizeof(buffer)-1)) {
            #ifdef LOGGING
            Serial.println("HttpClient>\tError: Buffer overflow.");
            #endif
            buffer[bufferPosition] = '\0'; // Null-terminate buffer
            client.stop();
            error = true;

            #ifdef LOGGING
            Serial.println("HttpClient>\tError: Response body larger than buffer.");
            #endif
        }
        bufferPosition++;
    }
    #ifdef LOGGING
    Serial.println("HttpClient>\tTerminating  Buffer.");
    #endif
    buffer[bufferPosition] = '\0'; // Null-terminate buffer

i can see that the TCP Connection returns data in 128 bytes chunks, and it manages to receive two chunks, but when receiving the 257:th character it hangs.

If I run the same in the main loop the call returns, but after 256 characters the system logs an error

0000173096 [wiring] ERROR: recv error = 128

indicating that there is actually an error in the TCP client, but that this is recoverable while in the main loop.

I havn't run the code on a GSM Particle, but I have a Boron and a Electron at home and will do that tonight.

Any ideas on how to proceed?

I have now tested with my Boron as well and this device has the same behaviour. As for the electron I have problems connecting that to the mobile network, but will follow up on that once i get it working.

Now I have been able to get my Electron connected to the could and updated.

On the Electron, the LogHandler works as intended, which as far as I can see isolates this to a problem with the mesh devices.

I have now got this working. The problem was that the TCP client in 0.8.0-rc.27 (file spark_wiring_tcpclient_posix.cpp) has a

LOG(ERROR, "recv error = %d", errno);

where the tcp client in release 1.0.0 (file spark_wiring_tcpclient.cpp (i guess)) uses

DEBUG("recv(=%d)",ret);

Since LOG (propably) calls the Loghandlers for logging something breaks the kernel.

So by changing the TCPclient::available method to log using

DEBUG("recv(=%d)",ret);
//LOG(ERROR, "recv error = %d", errno);

this is only logged during debug and thus it wont halt the kernel.

A similar problem in the UDP client (file spark_wiering_udpclient_posix.udp)

int UDP::sendPacket(const uint8_t* buffer, size_t buffer_size, IPAddress remoteIP, uint16_t port) {
    LOG(TRACE, "sendPacket size %d, %s#%d", buffer_size, remoteIP.toString().c_str(), port);
	sockaddr_storage s = {};
    detail::ipAddressPortToSockaddr(remoteIP, port, (struct sockaddr*)&s);
    if (s.ss_family == AF_UNSPEC) {
        return -1;
    }

prevents the Papertrail LogHandler from working on mesh devices since it uses UDP::sendPacket to send its data.

1 Like

Can you file your findings as GitHub issue please?

See

1 Like

It’s Log handlers all the way down, eh? :rofl:

The issue seems to be closed but we’re still getting these errors from all our 3rd gen devices (deviceOS 1.4.2) as we use TCPclient to send data & also Papertrail to monitor our logs. Any ideas?

Thanks.

I did some quick checks in the code, and there seems to be no regression errors as far I can see.

Will try to set up some tests to see what I find on my end.

It seems like we receive this error for each TCPclient.available() we do. We use the TCPclient in our own HTTPclient. This error returns aprrox. 1 message per second. Having 80 devices in the field (and steadily growing) this adds a huge overload on our Papertrail log limit :wink:

I found the following in spark_wiring_tcpclient_posix.cpp but not sure if this is the TCPclient we use because it opens spart_wiring_tcpclient if I click through.

LOG(ERROR, "recv error = %d", errno);

Hi community, any idea why I’m still getting this error on all my devices in the field (and filling up my Papertrail logs)? Using deviceOS 1.4.4.
Thanks.

Hi community!
Boron 2.1.0, HttpClient 0.0.5
still [wiring] ERROR: recv error = 128

How to reopen issue #1673 ?

I had the same issue pop up using the TCPClient on Boron with DeviceOS 2.2.0. Electron on the same deviceOS was fine, as others have reported.

Interestingly, TCPClient was working fine on boron for a few weeks, and then with unrelated code changes today, this issue popped up. I may try to roll back the changes to see what line of code caused the issue.

It appears that filtering this message out using a logHandler level of LOG_LEVEL_NONE for wiring, as shown below, mitigates the problem, though this is fairly heavy-handed. I’d prefer to find a specific cause, but at least I can continue making progress on other things while I debug this.

SerialLogHandler logHandler(LOG_LEVEL_WARN, /* system level*/ {
    /* specific handling for application, unspecified categories will default to
     * LOG_LEVEL_INFO
     */ 
    {"app", LOG_LEVEL_WARN},
    {"wiring", LOG_LEVEL_NONE}     // this mitigates the problem
});
1 Like