Посмертно. Один-єдиний пробіл



Ми — невеликий стартап в Чарльстоні, Південна Кароліна. Ми приймаємо замовлення з допомогою текстових повідомлень і роздруковуємо їх безпосередньо в ресторанах.

Ми запустили eatabit.com в Чарльстоні майже рік тому. За цей час наш API роздрукував понад 9300 замовлень на їжу у наших клієнтів — це ресторани, стадіони, курси гольфу. Робота з мобільним зв'язком не відрізняється простотою — особливо в зонах з підвищеним навантаженням на мережу, як на стадіонах під час матчів, але наші системи відстежують ситуацію на зразок поганої якості сигналу або розривів.



Ніч з середи на четвер зазвичай друга після ночі з вівторка на середу по мінімальному завантаженні. Тому, коли монітори почали видавати хвилю попереджень близько опівночі, ми подумали, що це випадковість. На жаль, це була не вона…



Що ж, розриви бувають. Іноді в ресторан приходять нові співробітники, які висмикують з розетки вилку принтера, щоб «вимкнути на ніч», але в цей раз проблема виникла з УСІМА принтерами. Наш постачальник SIM-карт, T-Mobile, іноді перезавантажує базові станції, і на 60-90 секунд відключаються принтери в цілому районі, але не ВСІ принтери Чарльстона.

Ок, починаємо вирішувати проблему з лода самих принтерів…



Принтери на основі чіпсету Arduino Mega (ATMega 1280), тому ми запускаємо Arduino IDE і вивчаємо статус системи:

SYSTEM::State: Polling.
SYSTEM::Polling: SYSTEM::State: Idle.

WEB::Starting Poll!
WEB::Poll Request:

GET /v1/printer/***************/orders.txt HTTP/1.1
HOST: api.eatabit.io
Authorization: Basic***********************************************
User-Agent: Eatabit_Device/0.5.1
Content-Length: 67
Content-Type: application/x-www-form-urlencoded
Accept: */*
Connection: close

pickup_minutes=15&delivery_minutes=30&paper_status=1&cell_signal=15

WEB::Request Length: 351
WEB::Request Page Status: 0

AT+CSQ
+CSQ: 20,0
OK

GSM::CSQ:20

AT#SKTD=0,80,"api.eatabit.io",0,0
CONNECT

GSM::SEND: Socket Enabled
GSM::RCXV: Header Sent

HTTP/1.1 505 HTTP Version Not Supported
Connection: close
Server: Cowboy
Date: Wec, 21 Oct 2014 19:22:32 GMT
Content-Length: 0
Стоп... що?
HTTP/1.1 505 HTTP Version Not Supported

Дев'ять місяців ми працювали з цієї прошивкою Arduino без питань, а тепер це? Раптово? Опівночі? По всьому місту? Забавно… Що ж це таке?

Server: Cowboy
Наше додаток розгорнуто на Heroku, ми використовуємо веб-сервер Unicorn. Так що ж це за «Ковбой», який спілкується з нашим сервісом?
Так, пробуємо cURL і відтворюємо запит через командний рядок на моєму Маці:
curl "http://api.eatabit.io/v1/printer/***************/orders.text?pickup_minutes=30&delivery_minutes=90&state=ok" \
> -X GET \
> -u***************:****************** \
> -v \
> --user-agent "Eatabit_Device/0.5.1"

* Hostname was NOT found in DNS cache
* Trying 54.225.219.28...
* Connected to api.eatabit.io (54.225.219.28) port 80 (#0)
* Server auth using Basic with user'***************'
> GET /v1/printer/***************/orders.text?pickup_minutes=30&delivery_minutes=90&state=ok HTTP/1.1
> Authorization: Basic***********************************************<
> User-Agent: Eatabit_Device/0.5.1
> Host: api.eatabit.io
> Accept: */*
>
< HTTP/1.1 200 OK
* Server Cowboy is not blacklisted
< Server: Cowboy
< Connection: keep-alive
< Date: Mon, 21 Oct 2014 01:25:11 GMT
< Status: 200 OK
< Content-Type: text/plain
< Content-Length: 7
< Etag: "26f14889eed7cc4b3b78cc667c7ee9eb"
< Cache-Control: max-age=0, private, must-revalidate
< X-Request-Id: dce1a529-fff1-4222-b997-21d7c074487f
< X-Runtime: 1.135825
< Via: 1.1 vegur
<
* Connection #0 to host api.eatabit.io left intact
{0:0}{}%

Начебто все нормально… WTF?! Дивимося на прошивку Arduino, де створюється інша частина запиту.

if(isCommsBufferAvailable()) {
//make the chunk
uint8_t dataLength = snprintf(( char * )tempString, sizeof(tempString), 
"pickup_minutes=%hhu&delivery_minutes=%hhu&paper_status=%hhu&cell_signal=%hhu",
settings.getPickupMinutes(),
settings.getDeliveryMinutes(),
printer.hasPaper(),
gsmModem.getSignal()
);
uint8_t contentLength[4];
dataLength = strlen( ( char * ) tempString);
itoa(dataLength,( char * ) contentLength, 10);

IF_DEBUG(DEBUG_INFO) PORT_DEBUG.println("WEB::Starting Poll!");
reserveCommsBuffer();

//build the header for the POLL request
strcpy( ( char * ) commsOrderBuffer, "GET /v1/printer/");

strcat( ( char * ) commsOrderBuffer, ( char * ) settings.getIMEI());
strcat( ( char * ) commsOrderBuffer, "/orders.txt HTTP/1.1\r\n");
strcat( ( char * ) commsOrderBuffer, "HOST: ");
strcat( ( char * ) commsOrderBuffer, SERVER_NAME);
strcat( ( char * ) commsOrderBuffer, "\r\n");
strcat( ( char * ) commsOrderBuffer, "Authorization: Basic ");

strcat( ( char * ) commsOrderBuffer, ( char * ) settings.getAccess()); 
strcat( ( char * ) commsOrderBuffer, "\r\n");
strcat( ( char * ) commsOrderBuffer, "User-Agent: Eatabit_Device/");
strcat( ( char * ) commsOrderBuffer, SOFTWARE_VER);
strcat( ( char * ) commsOrderBuffer, "\r\n");
strcat( ( char * ) commsOrderBuffer, "Content-Length: ");
strcat( ( char * ) commsOrderBuffer, ( char * ) contentLength);
strcat( ( char * ) commsOrderBuffer, "\r\n");
strcat( ( char * ) commsOrderBuffer, "Content-Type: application/x-www-form-urlencoded\r\n");
strcat( ( char * ) commsOrderBuffer, "Accept: */*\r\n");
strcat( ( char * ) commsOrderBuffer, "Connection: close\r\n"); 
strcat( ( char * ) commsOrderBuffer, "\r\n");
strcat( ( char * ) commsOrderBuffer, ( char * ) tempString);
IF_DEBUG(DEBUG_BUFFERS) {
temp1 = strlen((char*) commsOrderBuffer);
PORT_DEBUG.println("WEB::Poll Request: ");
PORT_DEBUG.println((char*)commsOrderBuffer);
PORT_DEBUG.print("WEB::Request Length: ");
PORT_DEBUG.println(temp1); 
}
temp1 = gsmModem.requestPage( (uint8_t *) SERVER_NAME, PORT_NUMBER, commsOrderBuffer, commsOrderBuffer, ORDER_QUE_MAX_ORDER_SIZE);
IF_DEBUG(DEBUG_BUFFERS) {
PORT_DEBUG.print("WEB::Request Page Status: ");
PORT_DEBUG.println(temp1);
}

//go wait for the response
_state = WEB_WAIT_POLL;
} 
else {
IF_DEBUG(DEBUG_BUFFERS) PORT_DEBUG.println("WEB::Buffer In use!");
} 
break;

Стійте. Невже це… між URL HTTP версіями рядка є різниця — додатковий пробіл:

strcat( ( char * ) commsOrderBuffer, "/orders.txt HTTP/1.1\r\n");

Давайте перевіримо теорію, що Ковбой не може обробити більше одного символу пробілу між аналізованими параметрами, додавши додатковий пропуск до кінця URL.

curl "http://api.eatabit.io/v1/printer/***************/orders.text?pickup_minutes=30&delivery_minutes=90&state=ok " \
-X GET \
-u***************:****************** \
-v \
--user-agent "Eatabit_Device/0.5.1"

* Hostname was NOT found in DNS cache
* Trying 54.225.123.174...
* Connected to api.eatabit.io (54.225.123.174) port 80 (#0)
* Server auth using Basic with user'***************'
> GET /v1/printer/***************/orders.text?pickup_minutes=30&delivery_minutes=90&state=ok HTTP/1.1
> Authorization: Basic***********************************************<<
> User-Agent: Eatabit_Device/0.5.1
> Host: api.eatabit.io
> Accept: */*
>
< HTTP/1.1 505 HTTP Version Not Supported
< Connection: close
* Server Cowboy is not blacklisted
< Server: Cowboy
< Date: Mon, 27 Oct 2014 02:03:25 GMT
< Content-Length: 0
<
* Closing connection 0

Є!



Таким чином, в нашому коді знайдений баг (у формі зайвого пробілу). Але чому ж це все раптово почалося? Адже цей баг існував як мінімум дев'ять місяців на працюючій прошивці…



Що ж змінилося?

Server: Cowboy

Cowboy. Хто запустив цей сервер, який по-тихому заблокував (точніше, зробив некоректними) наші запити? Heroku? AWS? Поверхневий пошук в Гуглі не дав певної відповіді на це питання. Ми відправили запити і туди, і туди, і все ще чекаємо відповіді. Залишайтеся на зв'язку.

Джерело: Хабрахабр

0 коментарів

Тільки зареєстровані та авторизовані користувачі можуть залишати коментарі.